Closed andlem74 closed 9 months ago
Ich konnte das selbe beobachten, allerdings mit einem mittels MQTT gesetzten SOC (Topic war dasselbe wie bei manueller Eingabe: openWB/set/vehicle/0/soc_module/configuration/soc_start). Hier der zugehörige Thread: https://openwb.de/forum/viewtopic.php?p=91445#p91445
This reset to the initial SOC value seems to always happen approximately 12 h after charging has reached the target SOC value. Then, charging is started again, but SOC will jump right back to the real value. This pattern is repeated daily. This is despite the value of 72000 minutes entered as polling time for manual SOC in non-charging mode.
Behavior observed in Release 2.1.1 with a sold openWB.
The request of the manual soc has been rewritten in master branch with pr #1143. Do you still observe the same behaviour?
Ich habe mit einer Master-Version von 2023-10-23(?) das Verhalten gesehen, daß beim Abziehen des Steckers der SOC sich auf den Wert von vor dem Laden zurückgesetzt hat:
Ist das normal? Ich hätte erwartet, daß der zuletzt berechnete Wert bestehen bleibt.
Ich hatte bei meinen wenigen Ladungen noch nicht den Stecker viel länger stecken lassen als bis Ladungsende, kann also die 12h-Phase nicht bewerten.
Heute hatte ich nach Abziehen des Ladesteckers wieder ein Rücksetzen auf den manuell vor Beginn der Ladung eingegebenen Wert. Möglicherweise ist es auch in diesem Zusammenhang relevant, daß nach Trennung der DSL-Verbindung (und damit der Verbindung zur OpenWB-Cloud) und dem Wiederherstellen ebenfalls ein Rücksetzen auf den manuell eingegebenen Wert erfolgte. Vielleicht ist das für den bei mir beobachteten Effekt erforderlich.
@andlem74: Hast du nachts eine Zwangstennung der Internet-Verbindung? Sind die von Dir erwähnten 12h nach Erreichen des Ziel-SOC eventuell nur die Zeitspanne bis zur Zwangstrennung?
Das schöne an der 2.x Cloud ist, dass dort keine Topics hin gesendet werden. Heißt auch, dass nach einer Zwangstrennung keine veralteten Topics wieder in die openWB gesendet werden können. Daher würde ich die Cloud als Ursache vorerst ausschließen, lasse mich aber gerne eines Besseren belehren.
Meines Wissens habe ich keine Zwangstrennung. Mein manueller SoC setzt sich auch zurück auf den Anfangswert, wenn ich den Ladestecker trenne. Am 08.11.2023 um 13:42 schrieb DerHerrW @.***>: Heute hatte ich nach Abziehen des Ladesteckers wieder ein Rücksetzen auf den manuell vor Beginn der Ladung eingegebenen Wert. Möglicherweise ist es auch in diesem Zusammenhang relevant, daß nach Trennung der DSL-Verbindung (und damit der Verbindung zur OpenWB-Cloud) und dem Wiederherstellen ebenfalls ein Rücksetzen auf den manuell eingegebenen Wert erfolgte. Vielleicht ist das für den bei mir beobachteten Effekt erforderlich. @andlem74: Hast du nachts eine Zwangstennung der Internet-Verbindung? Sind die von Dir erwähnten 12h nach Erreichen des Ziel-SOC eventuell nur die Zeitspanne bis zur Zwangstrennung?
—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you were mentioned.Message ID: @.***>
Nach dem heutigen Steckerabziehen habe ich ein paar logfiles. Ausgabe eines mqtt-clients, den ich auf das SOC-Setzen angesetzt habe ergibt
Nov 10 12:51:04 openWB/set/vehicle/0/soc_module/calculated_soc_state {"imported_start": 981715.94, "manual_soc": 49, "request_start_soc": false, "soc_start": 49} Nov 10 12:51:04 openWB/set/vehicle/0/soc_module/calculated_soc_state (null) Nov 11 09:40:23 openWB/set/vehicle/0/soc_module/calculated_soc_state {"imported_start": null, "manual_soc": 49, "request_start_soc": true, "soc_start": 49} Nov 11 09:40:23 openWB/set/vehicle/0/soc_module/calculated_soc_state (null)
Den Stand am 10.11. habe ich per UI eingegeben. Die Botschaft am 11.11. kam nach Abziehen des Steckers. Von der cloud web.openwb.de kam nichts. (Cloud ist aus der Konfiguration auch entfernt).
Hier die zwei Zeilen im Mainlog, wo die verschiendenen SOC genannt werden:
2023-11-11 09:40:31,330 - {control.data:266} - {INFO:MainThread} - cp3 ChargepointData(control_parameter=ControlParameter(chargemode='stop', current_plan=None, imported_at_plan_start=None, imported_instant_charging=None, limit=None, phases=0, prio=False, required_current=0, required_currents=[0.0, 0.0, 0.0], state=0, submode='stop', timestamp_auto_phase_switch=None, timestamp_perform_phase_switch=None, timestamp_switch_on_off=None), get=Get(charge_state=False, connected_vehicle=ConnectedVehicle(config=ConnectedConfig(average_consumption=17, charge_template=0, chargemode='stop', current_plan=0, ev_template=0, priority=False, time_charging_in_use=False), info=ConnectedInfo(id=0, name='Ladepunkt'), **soc=55.86**), currents=[0.0, 0.0, 0.0], daily_imported=0.0, daily_exported=0, evse_current=0, exported=0, fault_str='Kein Fehler.', fault_state=0, imported=984238.95, phases_in_use=1, plug_state=False, power=0, rfid_timestamp=None, rfid=None, soc=None, soc_timestamp=None, state_str='Keine Ladung, da kein Auto angesteckt ist.', voltages=[216.88, 221.36, 221.87]), set=Set(change_ev_permitted=[True, ''], charging_ev=-1, charging_ev_prev=-1, current=0, energy_to_charge=0, loadmanagement_available=True, log=Log(chargemode_log_entry='_', imported_at_mode_switch=0, imported_at_plugtime=0, imported_since_mode_switch=0, imported_since_plugged=0, range_charged=0, time_charged='00:00', timestamp_start_charging=None), manual_lock=False, phases_to_use=1, plug_state_prev=False, plug_time=None, required_power=0, rfid=None, target_current=0, charging_ev_data=<control.ev.Ev object at 0x758010d0>), config=Config(configuration={'mode': 'series', 'ip_address': 'localhost', 'duo_num': 0}, ev=0, name='Interne openWB', type='internal_openwb', template=0, connected_phases=3, phase_1=1, auto_phase_switch_hw=True, control_pilot_interruption_hw=True, id=3))
und etwas später
2023-11-11 09:40:31,335 - {control.data:266} - {INFO:MainThread} - ev0 EvData(set=Set(ev_template=EvTemplate(data=EvTemplateData(name='Standard-Fahrzeug-Profil', max_current_multi_phases=16, max_phases=2, phase_switch_pause=2, prevent_phase_switch=False, prevent_charge_stop=False, control_pilot_interruption=True, control_pilot_interruption_duration=4, average_consump=14000, min_current=6, max_current_single_phase=16, battery_capacity=32000, efficiency=87, nominal_difference=5, keep_charge_active_duration=40), et_num=0), soc_error_counter=0), charge_template=0, ev_template=0, name='Standard-Fahrzeug', tag_id=[], get=Get(**soc=49**, soc_timestamp='11/11/2023, 09:40:23', force_soc_update=False, range=0, fault_state=0, fault_str='Kein Fehler.'))
Möglicherweise wird der berechnete SOC vom cp3 nicht an das Fahrzeug ev0 übertragen.
Log hängt an. debuglog_socRuecksetzen.txt
Heute habe ich geladen mit der Option "Nur aktualisieren wenn angesteckt=Ja" in der Fahrzeugkonfiguration. Der SOC wurde nach Abstecken nicht zurückgesetzt.
Die Logik wurde mit #1251 nochmal überarbeitet. Bitte nochmal testen.
Irgendwo hakt es noch. Ich habe zwar den Stecker mit der neuen SW noch nicht entfernt, konnte aber schon Auffälligkeiten erkennen. Meine Beobachtungen:
Am 16.11.:
Der SOC bliebt zunächst so. Der Stecker ist weiterhin nicht gesteckt. Am 17.11.:
Im Mainlog habe ich einen Fehler gefunden: "2023-11-17 04:23:10,093 - {modules.update_soc:40} - {ERROR:SoC} - Fehler im update_soc-Modul Traceback (most recent call last): File "/var/www/html/openWB/packages/modules/update_soc.py", line 30, in update threads_update, threads_store = self._get_threads() File "/var/www/html/openWB/packages/modules/update_soc.py", line 45, in _get_threads ev_data = copy.deepcopy(data.data.ev_data) File "/usr/lib/python3.9/copy.py", line 146, in deepcopy y = copier(x, memo) File "/usr/lib/python3.9/copy.py", line 229, in _deepcopy_dict for key, value in x.items(): RuntimeError: dictionary changed size during iteration"
Topic__openwb_set_vehicle_0.txt
openWBMainlog.txt
log_soc_helper.txt
Kann der Fehler
"<class 'TypeError'> unsupported operand type(s) for -: 'float' and 'NoneType'"
dadurch kommen, daß mein soc_helper den soc jetzt als Integer an die Wallbox telefoniert statt als float? Ich habe das eingeführt, damit ein Setzen auch in Software 1.9 funktioniert, siehe auch https://openwb.de/forum/viewtopic.php?t=7451&start=40
Heute kurz nach dem Abstecken wurde der SOC ebenfalls wieder auf 0% gesetzt.
Der Stecker wurde um 12:15:21 Uhr abgezogen. Das schon erwähnte Topic hat empfangen: Nov 18 12:15:00 openWB/set/vehicle/0/get/soc 64.58 Nov 18 12:15:00 openWB/set/vehicle/0/get/soc (null) Nov 18 12:15:31 openWB/set/vehicle/0/get/force_soc_update true Nov 18 12:15:31 openWB/set/vehicle/0/get/force_soc_update (null) Nov 18 12:15:40 openWB/set/vehicle/0/get/force_soc_update false Nov 18 12:15:40 openWB/set/vehicle/0/set/soc_error_counter 0 Nov 18 12:15:40 openWB/set/vehicle/0/get/soc_timestamp "11/18/2023, 12:15:40" Nov 18 12:15:40 openWB/set/vehicle/0/get/fault_str "<class 'TypeError'> unsupported operand type(s) for -: 'NoneType' and 'float'" Nov 18 12:15:40 openWB/set/vehicle/0/get/fault_state 2 Nov 18 12:15:40 openWB/set/vehicle/0/get/force_soc_update (null) Nov 18 12:15:40 openWB/set/vehicle/0/set/soc_error_counter (null) Nov 18 12:15:40 openWB/set/vehicle/0/get/soc_timestamp (null) Nov 18 12:15:40 openWB/set/vehicle/0/get/fault_str (null) Nov 18 12:15:40 openWB/set/vehicle/0/get/fault_state (null) Nov 18 12:16:36 openWB/set/vehicle/0/set/soc_error_counter 1 Nov 18 12:16:36 openWB/set/vehicle/0/get/soc_timestamp "11/18/2023, 12:16:36" Nov 18 12:16:36 openWB/set/vehicle/0/set/soc_error_counter (null) Nov 18 12:16:36 openWB/set/vehicle/0/get/soc_timestamp (null) Nov 18 12:16:36 openWB/set/vehicle/0/get/fault_str "<class 'TypeError'> unsupported operand type(s) for -: 'NoneType' and 'float'" Nov 18 12:16:36 openWB/set/vehicle/0/get/fault_state 2 Nov 18 12:16:36 openWB/set/vehicle/0/get/fault_str (null) Nov 18 12:16:36 openWB/set/vehicle/0/get/fault_state (null) Nov 18 12:17:31 openWB/set/vehicle/0/set/soc_error_counter 2 Nov 18 12:17:31 openWB/set/vehicle/0/get/soc_timestamp "11/18/2023, 12:17:31" Nov 18 12:17:31 openWB/set/vehicle/0/set/soc_error_counter (null) Nov 18 12:17:31 openWB/set/vehicle/0/get/fault_str "<class 'TypeError'> unsupported operand type(s) for -: 'NoneType' and 'float'" Nov 18 12:17:31 openWB/set/vehicle/0/get/fault_state 2 Nov 18 12:17:31 openWB/set/vehicle/0/get/soc_timestamp (null) Nov 18 12:17:31 openWB/set/vehicle/0/get/fault_str (null) Nov 18 12:17:31 openWB/set/vehicle/0/get/fault_state (null) Nov 18 12:18:26 openWB/set/vehicle/0/set/soc_error_counter 3 Nov 18 12:18:26 openWB/set/vehicle/0/get/soc 0 Nov 18 12:18:26 openWB/set/vehicle/0/set/soc_error_counter (null) Nov 18 12:18:26 openWB/set/vehicle/0/get/soc (null) Nov 18 12:18:26 openWB/set/vehicle/0/get/range 0 Nov 18 12:18:26 openWB/set/vehicle/0/get/soc_timestamp "11/18/2023, 12:18:26" Nov 18 12:18:26 openWB/set/vehicle/0/get/range (null) Nov 18 12:18:26 openWB/set/vehicle/0/get/fault_str "<class 'TypeError'> unsupported operand type(s) for -: 'NoneType' and 'float'" Nov 18 12:18:26 openWB/set/vehicle/0/get/soc_timestamp (null) Nov 18 12:18:26 openWB/set/vehicle/0/get/fault_state 2 Nov 18 12:18:26 openWB/set/vehicle/0/get/fault_str (null) Nov 18 12:18:26 openWB/set/vehicle/0/get/fault_state (null)
Im Mainlog keine direkt erkennbaren zusammenhängende Fehler:
2023-11-18 12:06:16,554 - {helpermodules.setdata:330} - {ERROR:Setdata} - Payload ungültig: Topic openWB/set/chargepoint/3/set/current, Payload 2 liegt in keinem der angegebenen Wertebereiche. 2023-11-18 12:06:41,105 - {control.counter_all:101} - {ERROR:MainThread} - Ungültiger Hausverbrauch: -297.59999999403954W, Berücksichtigte Komponenten neben EVU [{'id': 6, 'type': 'inverter', 'children': [{'id': 5, 'type': 'bat', 'children': []}]}, {'id': 3, 'type': 'cp', 'children': []}, {'id': 5, 'type': 'bat', 'children': []}] 2023-11-18 12:07:20,735 - {control.counter_all:101} - {ERROR:MainThread} - Ungültiger Hausverbrauch: -85.97000915527303W, Berücksichtigte Komponenten neben EVU [{'id': 6, 'type': 'inverter', 'children': [{'id': 5, 'type': 'bat', 'children': []}]}, {'id': 3, 'type': 'cp', 'children': []}, {'id': 5, 'type': 'bat', 'children': []}] 2023-11-18 12:37:10,823 - {control.counter_all:101} - {ERROR:MainThread} - Ungültiger Hausverbrauch: -17.300048828125W, Berücksichtigte Komponenten neben EVU [{'id': 6, 'type': 'inverter', 'children': [{'id': 5, 'type': 'bat', 'children': []}]}, {'id': 3, 'type': 'cp', 'children': []}, {'id': 5, 'type': 'bat', 'children': []}] 2023-11-18 12:57:01,381 - {control.counter_all:101} - {ERROR:MainThread} - Ungültiger Hausverbrauch: -1.899993896484375W, Berücksichtigte Komponenten neben EVU [{'id': 6, 'type': 'inverter', 'children': [{'id': 5, 'type': 'bat', 'children': []}]}, {'id': 3, 'type': 'cp', 'children': []}, {'id': 5, 'type': 'bat', 'children': []}] 2023-11-18 16:29:40,173 - {modules.update_soc:40} - {ERROR:SoC} - Fehler im update_soc-Modul Traceback (most recent call last): File "/var/www/html/openWB/packages/modules/update_soc.py", line 30, in update threads_update, threads_store = self._get_threads() File "/var/www/html/openWB/packages/modules/update_soc.py", line 45, in _get_threads ev_data = copy.deepcopy(data.data.ev_data) File "/usr/lib/python3.9/copy.py", line 146, in deepcopy y = copier(x, memo) File "/usr/lib/python3.9/copy.py", line 229, in _deepcopy_dict for key, value in x.items(): RuntimeError: dictionary changed size during iteration
Bitte nochmal mit der aktuellen Version testen.
Mist - gerade aus versehen die Rückmeldung gelöscht.
Ich habe Version 2023-11-21 12:36:53 +0100 [8009e5a8b]:
SOC wurde gerade wieder einige Zeit nach Ladebeginn rückgesetzt:
Main-Log endet am 22.11.
MQTT-Log endet am 21.11.
SOC-Log ist gefüllt mit solchen Meldungen:
2023-11-23 13:28:22,167 - {modules.common.fault_state:55} - {ERROR:fetch soc_ev0} - Manueller SoC: FaultState FaultStateLevel.ERROR, FaultStr <class 'TypeError'> unsupported operand type(s) for -: 'float' and 'NoneType', Traceback: Traceback (most recent call last): File "/var/www/html/openWB/packages/modules/common/configurable_vehicle.py", line 66, in update car_state = self._get_carstate_by_source(vehicle_update_data, source) File "/var/www/html/openWB/packages/modules/common/configurable_vehicle.py", line 112, in _get_carstate_by_source return CarState(soc=calc_soc.calc_soc(vehicle_update_data, File "/var/www/html/openWB/packages/modules/vehicles/common/calc_soc/calc_soc.py", line 13, in calc_soc imported_since_start = vehicle_update_data.imported - imported_start TypeError: unsupported operand type(s) for -: 'float' and 'NoneType'
Mein eigener MQTT-Logger, der set-SOC-Topics mitschneidet, zeigt ähnliches:
openWBset.log.txt
In calc_soc.py findet sich die Zeile
"imported_since_start = vehicle_update_data.imported - imported_start"
Ich vermute, daß imported_start nicht explizit als float klassifiziert ist, also "NoneType".
Ich könnte mir vorstellen, dass beim aufruf der Funktion manchmal kein Typ definiert ist. Fehlt ein Argument am Aufruf? Trotzdem seltsam, da in der Funktion inported_start als float deklariert ist...
Bitte das Debuglevel auf Details stellen und mehrere komplette Durchläufe aus dem SoC-Log unter System->Fehlersuche posten, wenn das Problem auftritt. Sensible Daten wie Benutzernamen und Kennwörter unkenntlich machen.
Hier wie gewünscht das SOC-Log auf Debug-Level. Der letzte Eintrag vor dem ersten Eintrag der Datei ist von 14:20 und hat vmtl mit dem Fehler nichts zu tun.
Die 67% hat mein soc_helper beim Anfahren an die Wallbox eingetragen. Die 68% gegen Ende habe ich per Hand eingegeben. Danach läuft das Laden wie gewollt. Mein Topic zum Setzen des Manuellen SOC ist openWB/set/vehicle/0/soc_module/calculated_soc_state/manual_soc
.
Hier hat noch jemand anders das Problem.
Bei mir tritt das Problem nicht auf. Bitte die dokumentierte Schnittstelle über das MQTT-Modul nutzen oder das manuelle SoC-Modul nur über das Eingabefeld in der openWB verwenden. Es ist nicht vorgesehen, dass der manuelle SoC außerhalb der openWB gesetzt wird.
Neue Erkenntnis: Ich sehe den Fehler auch dann, wenn ich den SOC per Hand vorgebe:
imported_start in configurable_vehicle ist None, wenn keine Ladung stattfindet, während man einen SOC setzt.
Der Fehler kommt nicht, wenn ich nach Start der Ladung (und in diesem Fall Auftreten des Fehlers) einen SOC setze.
In diesem Fall wird imported_start auf den Wert des Stromzählers gesetzt. Dies habe ich nur im MQTT-Explorer gesehen, im socLog.txt ist davon nichts zu sehen:
2023-11-25 22:12:10,603 - {modules.common.configurable_vehicle:57} - {DEBUG:fetch soc_ev0} - Calculated SoC-State CalculatedSocState(imported_start=None, manual_soc=46, soc_start=45)
Im MQTT-Explorer konnte ich sehen, daß imported_start=None, manual_soc=46 nur für kurze Zeit (ein Regeldurchlauf, 10s?) stand, danach sprang imported_start auf den aktuellen Zählerstand und manual_soc wieder auf "Null"
Heute noch ein wenig in den Code geschaut. Für mich sieht der Fehler wie folgt aus: Nach Eingabe eines manuellen SOC (hier im Beispiel 69%):
calculated_soc_state = imported_start:null, manual_soc:69, soc_start: ..was immer voher drin stand..
Wenn das so bliebe, würde _get_carstate_source den Wert MANUAL zurückgeben und _get_carstate_by_source würde in Zeile 119 abbiegen. Deshalb funktioniert das Laden, wenn nach Ladebeginn manuell ein SOC gesetzt wird.
Nun wird nach 10s manual_soc von irgendwoher genullt (im MQTT-Explorer gut zu sehen):
calculated_soc_state= imported_start:null, manual_soc:null, soc_start:69
Wenn die Ladung nun erst beginnt, wird _get_carstate_source den Wert CALCULATION zurückgeben. Damit springt _get_carstate_by_source in Zeile 112 - und weil imported_start=None ist, tritt der Fehler (siehe) auf.
Der Fix könnte sein, das automatische Übernehmen von manual_soc nach soc_start zu verhindern - da kann ich aber die Nebenwirkungen auf andere SOC-Module nicht richtig einschätzen. Ich weiss auch nicht, in welcher Funktion das geschieht.
Bitte testen, ob die in PR # 1280 korrgierte Zeile das Setzen von imported_start verhindert hat.
Also das Laden wurde jedenfalls begonnen und läuft ohne Rücksetzen. Ich glaube aber, der grundsätzliche Fehlermechanismus ist noch vorhanden:
Jetzt tritt der Fehler nur einmal in Zeile 66 auf, bevor in Zeile 71 imported_start gesetzt wird. Das wird von der Fallback-Lösung noch geduldet.
Als Hotfix funktionert die Änderung, sauber wäre es aus meiner Sicht, wenn in _get_carstate_by_source auch source == SocSource.MANUAL wäre - irgendwie scheint die Funktion darauf zu beharren, daß beim ersten Aufruf source == SocSource.CALCULATION sei.
Bei mir hat das Laden jetzt fehlerfrei funktioniert. Leider hatte ich DEBUG nicht an, als der Stecker gesteckt wurde. Das SOC-Log ist aber leer, der MQTT-Explorer zeigt keine verdächtigen Botschaften und in meinem zusätzlichen MQTT-Logger ist auch nichts zu sehen, was auf ein Problem hindeutet.
Ich schlage vor, diesen Issue zu schließen. Hier wurden ja verschiedene Fehler behandelt und behoben.
Sollte noch ein Problem auftauchen, würde ich es mit passender Überschrift in einem neuen Issue einbringen. Jetzt bliebe noch zu prüfen, ob das Problem des PSA-Moduls, von dem in der Beta4 ebenfalls berichtet wird, hiermit behoben ist.
In manual SOC mode, the user entered an initial SOC of e. g. 15%. After the SOC has reached its target value, e. g. 80% the SOC displayed is reset to the initial value, e. g. 15%, after the polling delay for non-charging state (default is 720 minutes) has passed. This is both incorrect and confusing. Charging will restart from this incorrect value.