ahoy
ahoy copied to clipboard
lumapu
[Bug] <TOPIC>/<INVERTER_NAME>/available geht im Minutentakt von 2 auf 1 (available but not producing)
Platform
ESP32
Assembly
I did the assebly by myself
nRF24L01+ Module
nRF24L01+ plus
Antenna
external antenna
Power Stabilization
Elko (~100uF)
Connection picture
- [ ] I will attach/upload an Image of my wiring
Version
0.7.13
Github Hash
ac57e16
Build & Flash Method
AhoyDTU Webinstaller
Setup
Inverter: intervall 5 seconds MQTT: used, base topic "solar", interval 0
Debug Serial Log output
No response
Error description
Beginnend mit Version 0.7.6 und jetzt mit 0.7.13 geht der Inverter (Hoymiles HM-400) im Minutentakt auf "available but not producing" und nach 3 Sekunden wieder auf "available and is producing". Zeigt sich in der Ahoy GUI und in MQTT in Topic "solar/HM-400/available", das geht auf 1 und danach wieder auf 2. Gleichzeitig geht P_AC auf 0.
Ich habe in NodeRED das available-Topic aufgezeichnet:
Man sieht: Um 9:33:52 geht es auf 1, um 9:33:55 wieder auf 2, usw. jede Minute.
In meinem Dashboard sieht das dann so aus, das ist die Darstellung von P_AC:
Der linke Teil der Kurve (Werte vom Donnerstag) ist Version 0.7.4, da tritt das Problem nicht auf. Gegen 21:30 habe ich 0.7.13 geflasht. Freitag morgen ist die Kurve keine Kurve, sondern eine Fläche, weil P_AC ständig zwischen 0 und einem Wert hin und her pendelt. Ab ca 10 Uhr habe ich wieder zurück geflasht auf 0.7.4, da ist es wieder normal, die Kurve ist nicht gerade, weil es heute morgen sehr wolkig ist, aber sie geht nicht immer auf 0 runter.
Wie schon geschrieben, das habe ich auch schon bei 0.7.6 gesehen, bin dann aber wieder auf 0.7.4 zurück. Gestern wollte ich es mal wieder mit einer neuen Version probieren.
Ich habe auch einen seriellen Log aufgezeichnet, kann darin aber nichts ungewöhnliches sehen: ahoy.log.zip
Probiere mal 7.11 und 7.12 aus, ab wann das Problem rein kommt. 7.11 funktioniert bei mir noch.
Whoww ! 😲
Zeig mal den Flow. Wie holst Du den Topic und zerstückelst Du ihn oder holste ihn mit einem eigenen Node ?
Die 3s finde ich spannend !
Die WebGUI macht diese Sprünge aber nicht ?
Was sag das Serial-Log im WebGUI ?
Doch, die Web UI hat das auch, jetzt grade ist Version 0.7.5 drauf:
Fehler:
Kein Fehler:
Im Moment tritt der Fehler jede Minute zwischen Sekunde 06 und 09 auf, im Log steht aber nichts relevantes drin, ich sehe zumindest nichts:
14:16:02 I: (#0) resetPayload
14:16:02 I: (#0) enqueCommand: 0x0b
14:16:02 I: (#0) prepareDevInformCmd 0x0b
14:16:02 15 pid: 80
14:16:02 I: TX 27B Ch61 | 15 83 20 53 82 89 32 97 72 80 0b 00 64 ba 77 02 00 00 00 01 00 00 00 00 ce 30 e6
14:16:02 W: (#0) Frame 2 missing: Request Retransmit
14:16:02 15 pid: 82
14:16:02 I: TX 11B Ch75 | 15 83 20 53 82 89 32 97 72 82 bb
14:16:02 W: (#0) Frame 2 missing: Request Retransmit
14:16:02 15 pid: 82
14:16:02 I: TX 11B Ch3 | 15 83 20 53 82 89 32 97 72 82 bb
14:16:02 I: procPyld: cmd: 0x0b
14:16:02 I: procPyld: txid: 0x95
14:16:07 I: (#0) resetPayload
14:16:07 I: (#0) enqueCommand: 0x0b
14:16:07 I: (#0) prepareDevInformCmd 0x0b
14:16:07 15 pid: 80
14:16:07 I: TX 27B Ch23 | 15 83 20 53 82 89 32 97 72 80 0b 00 64 ba 77 07 00 00 00 01 00 00 00 00 9e 0f 8c
14:16:07 I: procPyld: cmd: 0x0b
14:16:07 I: procPyld: txid: 0x95
14:16:12 I: (#0) resetPayload
14:16:12 I: (#0) enqueCommand: 0x0b
14:16:12 I: (#0) prepareDevInformCmd 0x0b
14:16:12 15 pid: 80
14:16:12 I: TX 27B Ch40 | 15 83 20 53 82 89 32 97 72 80 0b 00 64 ba 77 0c 00 00 00 01 00 00 00 00 ae 7c c4
14:16:12 W: (#0) Frame 2 missing: Request Retransmit
14:16:12 15 pid: 82
14:16:12 I: TX 11B Ch61 | 15 83 20 53 82 89 32 97 72 82 bb
14:16:12 W: (#0) Frame 2 missing: Request Retransmit
14:16:12 15 pid: 82
14:16:12 I: TX 11B Ch75 | 15 83 20 53 82 89 32 97 72 82 bb
14:16:12 I: procPyld: cmd: 0x0b
14:16:12 I: procPyld: txid: 0x95
Und es ist jede Minute genau zur gleichen Zeit ... immer 3 Sekunden lang
das habe auch noch nie gehört, was ist hier nur los? Kannst du bitte testweise mal MqTT abschalten (Broker IP in den Einstellungen löschen). Habe den Verdacht, dass das von extern reinkommen könnte. Hast du eine weitere DTU parallel laufen? Hast du eine Möglichkeit die AC Leistung per Zwischenstecker (grob) zu verifizieren?
- Ohne MQTT tritt das Problem auch auf
- Mit 0.7.4 (fd33099) tritt das Problem nicht auf
- Ab 0.7.5 tritt es auf, mit 0.7.6 und 0.7.13 habe ich es auch getestet, keine Änderung
- Es ist auch nicht der Inverter, ich sehe am Stromzähler keine Änderung, wenn Ahoy auf P_AC=0 / available=1 geht
- Um auszuschließen, dass es eine verkorkste Konfiguration ist, habe ich bei installierter 0.7.13 "Erase settings (not WiFi)" durchgeführt (Werksreset) und alles 'händisch' wieder eingetragen (also kein Backup zurück gespielt), trotzdem selbes Problem ...
Das Interessante ist, dass man die Uhr danach stellen kann, es ist exakt jede Minute.
Ich kann kein C++, aber wenn ich mir hier auf GitHub die Änderungen für den Commit 0.7.5 ansehe, dann wurde da was in einer Prozedur app:tickMinute geändert, die laut Kommentar "only triggered if 'reset values on no avail is enabled'" und das Flag ist in meiner Konfiguration gesetzt ...
EDIT Und ich hab es ausprobiert: wieder 0.7.13 geflasht und den Haken entfernt und neu gestartet und das Problem ist weg: P_AC geht nicht im Minutentakt auf 0 W und available bleibt stabil auf 2 !
Ah, OK. Ich habe den Haken nicht sitzen. Schätze mal das dieser Bug schon lange drin ist und es halt noch niemand bemerkt hat, bzw. Den Haken da gesetzt hat. Sonst wäre es wohl schon aufgefallen 😲
zusammengefasst heißt das, dass der Haken bei Reset values when inverter status is 'not available' den Status des gesamten Inverters verändert?
Ich schaue mal über den Code, der durch einen hier gesetzten Haken ausgeführt wird.
Beim Inverter passiert gar nichts (ich hab ja oben geschrieben, dass ich am Stromzähler direkt keine Schwankungen sehe), ich bin der Meinung, das passiert rein innerhalb von Ahoy.
verwendest du zufällig Ahoy mit der Option Start without time sync (useful in AP-Only-Mode)? Das würde nämlich erklären warum die Werte immer wieder zurückgesetzt werden (natürlich in Kombination mit dem oben genannten Haken)
dann muss ich mal testen was meine Ahoy-DTU macht, wenn ich den von dir genannten Haken setzte. Laut Code dürfte nichts passieren - aber oft reicht Code lesen nicht aus.
Hatte das gleiche Problem mit der Ahoi-DTU V 0.7.26 (Wemos D1 Mini und nRF24L01+ mit PCB Antenne Abstand zum Inverter ca. 12m mit Hauswand dazwischen. Ich warte noch auf das Modul mit ext. Antenne).
Das Setting 'Reset values when inverter status is 'not available' ist per default gesetzt. Es abzuschalten hat bei mir geholfen. Die Werte gehen jetzt zwischenzeitlich nicht mehr auf 0 wie man in der Homassistant MQTT History der Sensoren deutlich beobachten kann.
Heißt das jetzt, dass die Verbindung zum meinem HM-800 in regelmäßigen Abständen fehl schlägt oder ist das ein systematischer Fehler? Wenn irgendwelche Logs helfen sollten kann ich die gerne ziehen.
Hier der Vergleich vor und nach dem Löschen der Checkbox:
Das ist ein Bug in Ahoy, Dein Inverter und die Funkverbindung sind OK. Kam mit der Entwicklungsversion 0.7.5 rein und fiel bisher nicht groß auf. Wenn der Haken bei 'Reset values when inverter status is 'not available' aber jetzt bei allen gesetzt ist, die auf 0.7.26 upgraden, wird das gehäuft auffallen.
Habe selbiges Problem. Hatte glaube ich die 0.6.9er Version drauf ohne diese Fehler. Mit der 0.7.36 und drüber kommt es zu den oben genannten Aussetzer. Dummerweise auch wenn ich zurück auf die 0.6.9 Version gehe bleibt dieses Problem bestehen. Ein Inverter läuft bei mir als Nachteinspeisung. Wenn ich da das Häckchen "Reset values when inverter status is 'not available'" nicht setzte bleibt der letzte Wert bestehen, obwohl der WR nichts mehr produziert.
Zurück auf die 0.7.2 da läuft es.
0.7.4 ist die letzte Version, bei der es noch funktioniert. Der Fehler kam wohl mit 0.7.5 rein ...
Gleiches Problem hier.
Wie schon @GrisuXX festgestellt hat ist der Workaround mit dem "Reset values.." Häkchen etwas holprig. Auch mein Inverter wird wird aus einem Akku versorgt und primär durch ein/ausschalten der DC-Spannung gesteuert. Das Entfernen des Häkchens führt nun dazu, dass zwar das available MQTT topic auf den Status 4 geht wenn ich dem Inverter die Versorgung abschalte, Ahoy aktualisiert in diesem Zuge aber (zum Beispiel) das ch0/P_AC topic nicht mehr.
Ich werde das downgrade auf 0.7.4 testen.
Bin ich der Einzige bei dem das Problem immer noch auftritt? Gerade frisch getestet mit 0.8.82 --> das Häkchen "Reset values when inverter status is 'not available'" war nach dem Upgrade gesetzt, Inverter springt ständig zwischen available Status 2 und 3 herum. Häkchen raus -> alles gut (bis auf das bereits diskutierte Verhalten, dass dann natürlich die Werte nicht resettet werden, wenn der Inverter tatsächlich offline geht).
sehr interessant, danke für den Hinweis
Ich hab' grad nochmal etwas getestet und dir die MQTT Kommunikation am Broker mitgeschnitten, evt. hilfts ja beim debuggen. Falls ich sonst irgendwie helfen kann einfach melden.
reset_values_when_na_ON.txt reset_values_when_na_OFF.txt
EDIT: ich seh grad eventuell ist das Verhalten so gewollt, bzw. hat nichts mit dem hier ursprünglichen Problem zu tun, sorry!
Mein Problem hier ist eher die Tatsache, dass der Inverter wenn das "reset values.." aktiv ist, regelmässig in den available Status 3 schaltet, aber falls das OK ist so muss ich mein FHEM setup anpassen ;-)
lg, Jürgen
Meine 2 Cent: Der Bug ist m.E. mit dem Commit für 0.7.5 rein gekommen. https://github.com/lumapu/ahoy/commit/76f01bbe958c7ae3a3263ddd9499d90d04e458fe#diff-313fbc20401c955c6defe4eafd6b0049c30478d5752c647d384b420e4f305e2bL341 Zeile 341: void app::tickMinute(void) { // only triggered if 'reset values on no avail is enabled'
In 0.7.4 war noch alles i.O.
hey super was ihr hier ab Infos zusammen sammelt, da kann man den Fehler viel leichter nachstellen und hoffentlich dann auch beheben
ich habe jetzt echt lange auf den Code geschaut, kann den Fehler aber nicht sehen. Hier eine Zusammenfassung evtl. hilt es den Fehler weiter einzugrenzen:
- jeder Inverter geht auf
not available, wenn er keine Live Daten in den letzten 5 Minuten bekommen hat - ist der Schwellwert noch nicht unterschritten wird nichts zurückgesetzt
- stimmt die Systemzeit bei euch auf dem ESP?
Was ich in der 0.8.85 geändert habe:
- jetzt wird Available nur noch auf die Live Daten bezogen
Was ich nicht verstehen / nachvollziehen kann:
- warum der Status zwischen 2 und 3 wechsel sollte. Wie ist hier der Zustand? DC Power off? Für wie lange? DC Power Off bedeutet 0W Produktion was natürlich in
not producingresultieren muss - warum meine Änderung in
0.7.5hier Einfluss nehmen sollte, die Änderung sieht sauber aus, aber das Resultat (ganz oben ist eindeutig ...)
- stimmt die Systemzeit bei euch auf dem ESP?
bei mir ja
Was ich nicht verstehen / nachvollziehen kann:
- warum der Status zwischen 2 und 3 wechsel sollte. Wie ist hier der Zustand? DC Power off? Für wie lange? DC Power Off bedeutet 0W Produktion was natürlich in
not producingresultieren muss
Nein, mein Inverter war während des MQTT-Sniffs immer online und hat produziert, aber dein "DC Power off" bringt mich auf eine Idee: mein Inverter wird aus einem 8S Akku versorgt und befindet sich dadurch dauerhaft unter der Spannungsschwelle, bei der die MPPT Regelung des HM-300 PV-Eingangs anspringt. Kanns sein dass der Inverter das irgendwie in seinem Status meldet und das eventuell von AhoyDTU "missverstanden" wird?
Bei mir ist das alles recht leicht zu reproduzieren (da der Inverter ja immer mit annähernd gleicher Spannung versorgt wird und sich daher hoffentlich auch immer gleich verhält), falls ich also noch irgendwelche Daten liefern kann einfach bescheid sagen.
lg, Jürgen
Update: ich habe gerade nochmal mit 0.8.85 getestet, Einstellung reset values when inverter is n/a war aktiv. Habe dir auch einen export der webserial seite erstellt und timestamps zum MQTT output hinzugefügt.
Zur Info: ich habe die reset values..Einstellung eingeschaltet, AhoyDTU rebootet und nach dem reboot den Inverter eingeschaltet (DC-Versorgung über den PV-Eingang).
AhoyDTU_0.8.5_reset_val_ON.txt webserial.txt
Verhalten war so weit ich das sehe gleich wie in 0.8.82.
EDIT: Eventuell noch relevant: mein "Interval" in den Inverter Settings steht auf 15 Sekunden.
Ich hab ein ganz simples Balkonkraftwerk: 1 x 400 W-Panel an einem HM400, keine Batterie, nichts ...
Zu Deinen Fragen:
-
jeder Inverter geht auf not available, wenn er keine Live Daten in den letzten 5 Minuten bekommen hat
- Der Inverter schickt Daten, in der Web Konsole wird alle 10 Sekunden was angezeigt
-
ist der Schwellwert noch nicht unterschritten wird nichts zurückgesetzt
- Der Inverter produziert die gesamte Zeit, ich kann am Stromzähler keinen Leistungsabfall sehen
-
stimmt die Systemzeit bei euch auf dem ESP?
- Ja
-
Was ich in der 0.8.85 geändert habe:
- 0.8.85 werde ich noch testen, z.Z 0.8.83
-
warum der Status zwischen 2 und 3 wechsel sollte. Wie ist hier der Zustand? DC Power off? Für wie lange? DC Power Off bedeutet 0W Produktion was natürlich in not producing resultieren muss
- Wie gesagt, der Inverter produziert. Die Web UI zeigt 0 für DC Leistung, DC Spannung, DC Strom, AC Leistung, usw. Immer zur gleichen Sekunde (xx:xx:23) für 10 Sekunden, aber das ist wohl die Refresh Zeit.
-
warum meine Änderung in 0.7.5 hier Einfluss nehmen sollte, die Änderung sieht sauber aus, aber das Resultat (ganz oben ist eindeutig ...)
- Das war nur eine Vermutung von mir, mit 0.7.5 fing es an, und da war eine Änderung in genau dieser Funktion ...
Version 0.8.85 ändert nichts ... jeder Minute kurz offline
Das zeigt der Web Konsole Log, der Fehler tritt ca Sekunde 23 auf, der Log zeigt Daten bei Sekunde 26:
10:27:26.240 -----
10:27:26.241 I: com loop duration: 241ms
10:27:26.242 -----
10:27:36.121 I: (#0) RX 24ms | 27 CH75 | 95 01
10:27:36.122 I: (#0) RX 72ms | 27 CH61 | 95 82
10:27:36.124 -----
10:27:36.125 I: com loop duration: 124ms
10:27:36.125 -----
10:27:46.141 I: (#0) RX 46ms | 27 CH75 | 95 01
10:27:46.142 I: (#0) RX 92ms | 27 CH61 | 95 82
10:27:46.144 -----
10:27:46.145 I: com loop duration: 144ms
10:27:46.145 -----
10:27:56.126 I: (#0) RX 25ms | 27 CH75 | 95 01
10:27:56.127 I: (#0) RX 79ms | 27 CH61 | 95 82
10:27:56.130 -----
10:27:56.130 I: com loop duration: 131ms
10:27:56.131 -----
10:28:06.137 I: (#0) RX 44ms | 27 CH75 | 95 01
10:28:06.138 I: (#0) RX 88ms | 27 CH75 | 95 82
10:28:06.140 -----
10:28:06.141 I: com loop duration: 140ms
10:28:06.141 -----
10:28:16.122 I: (#0) RX 27ms | 27 CH75 | 95 01
10:28:16.123 I: (#0) RX 73ms | 27 CH61 | 95 82
10:28:16.125 -----
10:28:16.207 I: (#0) RX 34ms | 17 CH75 | 95 81
10:28:16.208 I: (#0) Inv loss: 0 of 12, DTU loss: 0 of 22. ACKs: 8
10:28:16.209 -----
10:28:16.209 I: com loop duration: 209ms
10:28:16.210 -----
10:28:26.105 I: (#0) RX 58ms | 27 CH61 | 95 81
10:28:26.107 -----
10:28:26.237 I: (#0) RX 35ms | 27 CH61 | 95 01
10:28:26.238 I: (#0) RX 82ms | 27 CH61 | 95 82
10:28:26.239 -----
10:28:26.241 I: com loop duration: 241ms
10:28:26.241 -----
Hab mir auch mal angeschaut, wie das über MQTT in NodeRED ankommt:
- Um 10:41:17 schickt Ahoy den Wert P_AC von 67.4 W
- Um 10:41:20 kommt im Topic "available" der Wert 3 ("available and was producing")
- Um 10:41.27 kommt P_AC von 67.3 W
- Um 10:41:28 wechselt available zurück auf 2
Da hat sich zu früher was verändert, MQTT sendet sehr wohl Werte, obwohl das WebUI 0 anzeigt. Mir ist das ursprünglich aufgefallen, als in meinem Dashboard plötzlich keine Kurve, sondern eine Fläche für die Leistung angezeigt wurde (mein erster Eintrag mit dem ich das Issue aufgemacht habe), weil die Leistung ständig zwischen 0 und irgendwas pendelt. Damals war es auch ein Wechsel zwischen Status available 1 und 2 (die anderen Stati gab es da glaube ich noch nicht)
Ah ja, also gleiches Verhalten wie bei mir. Damit wär natürlich geklärt dass es nichts mit meiner Akkuversorgung zu tun hat.