Temporarily reporting yieldtotal of 2113405kWh for HM-600 #1022
Comments
|
Some further information are required:
|
|
This is a single dtu (this openDTU) accessing a single HM-600 inverter, that 2 panels are attched to (and there seems no other pv close to us AFAIK/AFAIS). For the console snapshot I need to wait for the next time this is happening. I just started capturing the console as it is available by the web browser. Btw: the webapi documentation misses the description of the |
|
It happened again at 18:47:04. The websocket aborted at some time. Unfortunately I do not see any obvious timestamps. Hopefully there is one somewhere in the data shown in hex only ... ? Else I have to redo the capturing until next occurence with prepending each line with a timestamp ... ? |
|
Ok, it happened 3 times today. 3x single times propagating the Unfortunately I failed again to capture with prefixing by timestamp (found the correct statement but did not copy it to capturing script :-( ). 2 types of messages came to my intention: Following log excerps for each of the 4. Alays with one inverter fetch block before and afterwards (I could attach again full log if this is needed and if it helps also without timestamps). No 1 No 2 No 3 No 4 |
|
Just checked for the line numbers, those messages appeared. And I guess No 4 is not related to the 4th invalid number being reported. As it appeared much later only in the log. But should have been close to No 3 then: |
|
It just happened several times again. I just had a quick look to the log. And there are NO error messages arround the times it showed up. BUT: there was at least the last 2 times (that I have log now available for with millis resolution) some millis after the "Success" message in the end of the nominal "Fetch Inverter" block a log message starting another block for "TX AlarmData Channel", as shown below. Just as a guess, no time to check the code by now myself: is it possible that by bad timing it's handling clashes with an mqtt data propagation in progress? Do they use same mem (buffer?) that are not guarded against parallel access? (corrupted data arrived with time 10:57:45 at the homeassistant) |
|
Happened another 3 times now. Always as described before, with |
|
Folgendes macht mich stutzig: Hier kommen auf eine SystemConfigPara 3 Antwortpakete. Das dürfte garnicht sein. Kannst du ggf. mal einen Screenshot vom Inverter-Info Dialog posten? |
|
Hi, kann ich machen. Kann sich aber auch gleich erledigt haben :-) Ich habe mich gerade durch den Code gewühlt. Und verstehe ganz bestimmt noch nicht viel. Aber an einer ähnlichen Stelle bin ich auch gerade hängen geblieben - nur irgendwie umgekehrt. Die Fehlermeldungen korrelieren nicht mit den korrupten Daten (könnten aber dann doch damit zusammenhängen, komme ich später drauf zurück). Ich die Pakete oben von gestern "per Hand" dekodiert. Da stehen vernünftige Daten drin, nichts als korrupt für mich erkennbar. Könnte auch noch ne Nebenläufigkeit vlt sein - vor 2h war das noch meine Vermutung. a) "Fetch inverter" ist mit nur EINEM Paket zufriedengestellt? AFAIS müssten das immer 3 sein ... ? Im Sourcecode sehe ich allerdings nicht den Fall abgefangen, dass nur das erste Paket gekommen ist (mit b) Das RX Paket in "Fetch Inverter" ist exakt jenes aus dem "SystemConfigPara" zuvor c) Zufällig(?) sind die letzten beiden Bytes vor dem CRC d) Bei Deinen zu vielen Paketen, die zu Fehlermeldung führen, ist auch wieder dieses SystemConfigPara Command beteiligt Also IMHO liegt da irgendwo des Problems Ursache. Aber für heute steige ich an der Stelle erstmal aus. Wechselrichter Info: |
|
Oh man, im Fenster schließen sehe ich doch nochmal was ... hätte ich noch 2 Zeilen weiter nach oben geschaut ... vollständig steht da nämlich: Und bei dem Beispiel No 4 mit der Fehlermeldung, die Du angeschaut hattest desgleichen. Die ersten beiden Zeilen in meinem Log. AFAIU werden da 2 Commands quasi parallel in die Queue gegeben ... also doch eher eine Nebenläufigkeit? Ich glaube ich hatte eine Stelle gesehen, wo in eine Queue das Command reingeht. Und danach die Adresse des 1. Commands in der Queue als die dazu gehörige angenommen wird. Wenn jetzt das 2. Command in die Queue gepackt wird, bevor für das 1. die Adresse ermittelt wurde? Werden beide Cores der CPU (AzDelivery ESP32 D1 Mini) frei verwendet oder ist eine fest zB für WLAN reserviert? |
|
|
Kann ja nicht passieren. Das läuft linear auf einem Kern ab. Immer im Kontext der Main Loop. Verwende mal NICHT den Websocket der das Log ausgibt sondern wirklich die Serielle Schnittstelle. |
|
Ok, das dann nicht. An die serielle Schnittstelle komm ich so einfach & auf die Schnelle jetzt nicht ran. Hab mir gerade noch mal einen anderen Vorfall angeschaut, und jetzt auch mal die Command Pakete. Und danach steht für mich ziemlich fest, dass eintreffende Pakete einem falschen Command zugeordnet werden. Was aber nicht wirklich verwunderlich ist, da es AFAIS keine Möglichkeit gibt, die RX Pakete einem konkreten TX zuzuordnen. Per Zähler zB, ab da ist nichts dazu drin, weder im TX, noch im RX - jedenfalls soweit die Bedutung der Bits & Bytes bekannt ist (bei TX sind da noch ein paar Eine Zuordnung zum Command kann also nur über die Anzahl der erwarteten Pakete sowie deren Länge(n) erfolgen. Und das sehe ich derzeit nicht im Code. Dafinde ich nur die Prüfung, dass es gültige Paket Sequenz war - egal ob aus 1 oder 3 Paketen bestehend. Wenn also ein einzelnes SystemConfigPara Paket ankommt (warum auch immer) mit Fragment ID 81, kann das einem gerade wartenden RealTimerunData Command zugeordnet werden, ohne dass die Prüfung das ablehnt. Das einzelne Fragment wird per Was IMHO, mit dem was ich jetzt gesehen habe, rein muss, ist eine Prüfung vor dem Parsen Inverter spezifisch von:
Noch offen ist, warum der Inverter das SystemConfigPara Antwort Paket noch ein 2. Mal zu senden scheint, obwohl RealTimeRunData angefordert wurde. |
Absolut falsch! Es ist exakt bekannt was angefragt wurde, und nur das kann als Antwort kommen. Der Inverter hat einen festen Timeout innerhalb dessen er die Antwort liefert. Wenn innerhalb dieser Zeit nichts kommt, wird auch nicht mehr kommen. Die Frage ist, warum passiert das nur bei dir und sonst augenscheinlich nicht. Kann auch am Caching des Websockets liegen. Wie gesagt, direkte Serielle Verbindung. |
|
Mutige Aussage. Wo wir doch SEHEN, dass es auch anders sein kann ;-). Dass die richtige Antwort kommt ist "nur" eine Annahme. Nämlich dass der Inverter an der Stelle richtig sendet, Inhaltlich und was das Timing angeht. Können wir nicht sicherstellen, auch nicht anhand dessen Sourcecode sehen, und haben wir keinen Einfluß drauf. Im Gegenteil, genau wie mit korrupten Paketen müssen auch semantisch falsche Pakete, wo das möglich ist, erkannt und verworfen werden IMHO. Sonst ist es nicht robust. Anhand DER DATEN PAKETE ist diese eindeutige Zuordnung AFAIS nicht möglich. Und die beschriebenen semantischen Prüfungen fehlen halt noch. AFAIS kein Drama. Ich würde jetzt in InverterAbstract vor Zeile 169 eine Und ja, wäre sicher spannend herauszufinden warum dem so ist. Ändert aber nichts an den derzeit fehlenden Prüfungen der eingehenden Daten. |
Lese dir bitte den GESAMTEN Thread auf Microcontroller.net durch bevor du so etwas sagst. Das hat schon so seine Richtigkeit. Ist von Hoymiles genauso implementiert. |
|
Successfully running this afternoon your fix patched by what I provided to you as pr #1096: besides several CRC errors, 3x the check saved me from more parse results on wrong packets: |
|
great to hear that it's working... |
|
Shitty FW ... ok. But they are not wrong formatted. The inverter sends packets belonging to a different TX (again) while OpenDTU is waiting for a statistics packet. Search in the comments for For #1084 the CRC is valid, too, but I do not see the packet having arrived for another TX in the log. So the cause may be a different one. The countermeasure is the same ;-). |
|
I think we can consider this as closed... |
|
This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new discussion or issue for related concerns. |
What happened?
Suddenly 1st time/starting yesterday I see a yieldtotal reportedly at 2113405kWh. Multiple times already reporting this exact number.
Plus meanwhile twice a directly following update with still much too high but varying values.
No events/errors have been reported.
Nominal values ~28xkWh at the moment.
I have never seen this before (since 27.2.2023 when installing my "Balkonkraftwerk").
Yesterday it happened before and after having upgraded to the latest version.
And it happened also in the evening, so it does not seem tempreature related.
Yesterday I saw it only in the recording of my connected homeassistant, whose energy charts now got completely messed up.
Today I saw it "live", could check also some other values in the mqtt that are not announced to homeassistant sensors
(Btw: why? Just forgotten or by intention?)
That same time many other values go down to 0.
The is_valid at least for AC remained at 1.
To Reproduce Bug
No idea, it just happens
Expected Behavior
The data seems corrupted and should not be propagated
Install Method
Self-Compiled
What git-hash/version of OpenDTU?
Until 9.6. 18:25: aa4868c/v23.5.31 Afterwards: 170978c/v23.6.9
Relevant log/trace output
Anything else?
No response
The text was updated successfully, but these errors were encountered: