DPL wird nicht aktualisiert bei aktueller Version

[kutzera]

What happened?

nach Update auf 2024.11.20 bleibt der DPL dauernd hängen.
Nach neustart wird kurz der Einspeisewert einmal angepasst dann hängt sich das System wieder auf.

To Reproduce Bug

im normalen Betrieb

Expected Behavior

Permanente Anpassung des DPL

Install Method

Pre-Compiled binary from GitHub releases

What git-hash/version of OpenDTU-OnBattery?

2024.11.20

What firmware variant (PIO Environment)?

generic_esp32s3_usb

Relevant log/trace output

RX Period End
16:30:58.194 > All missing
16:30:58.202 > Nothing received, resend whole request
16:30:58.208 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:00.232 > RX Period End
16:31:00.281 > All missing
16:31:00.288 > Nothing received, resend whole request
16:31:00.294 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:02.280 > RX Period End
16:31:02.327 > All missing
16:31:02.333 > Nothing received, resend whole request
16:31:02.340 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:03.921 > [DPL inverter 114485010664]: timeout (18 in succession), state transition pending: yes, limit pending: yes
16:31:03.955 > [DPL inverter 114485010664]: issuing restart command after update timed out repeatedly
16:31:03.960 > [DPL::announceStatus] reloading DPL configuration
16:31:03.965 > [DPL::announceStatus] waiting for a start/stop/restart/limit command to complete
16:31:04.223 > RX Period End
16:31:04.231 > All missing
16:31:04.240 > Nothing received, resend count exeeded
16:31:04.247 > [DPL inverter 114485010664]: sending limit of 2.5 % (20 W respectively), max output is 800 W
16:31:04.533 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:05.146 > Interrupt received
16:31:05.184 > Frame kaputt
16:31:06.513 > RX Period End
16:31:06.522 > All missing
16:31:06.530 > Nothing received, resend whole request
16:31:06.536 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:08.628 > RX Period End
16:31:08.665 > All missing
16:31:08.673 > Nothing received, resend whole request
16:31:08.680 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:10.164 > Interrupt received
16:31:10.368 > Frame kaputt
16:31:10.573 > RX Period End
16:31:10.583 > All missing
16:31:10.592 > Nothing received, resend whole request
16:31:10.601 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:12.621 > RX Period End
16:31:12.632 > All missing
16:31:12.637 > Nothing received, resend whole request
16:31:12.643 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:13.850 > [DPL::announceStatus] waiting for a start/stop/restart/limit command to complete
16:31:14.593 > RX Period End
16:31:14.602 > All missing
16:31:14.616 > Nothing received, resend count exeeded
16:31:14.979 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:16.922 > RX Period End
16:31:16.931 > All missing
16:31:16.936 > Nothing received, resend whole request
16:31:16.944 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:18.969 > RX Period End
16:31:18.978 > All missing
16:31:18.983 > Nothing received, resend whole request
16:31:18.988 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:21.019 > RX Period End
16:31:21.027 > All missing
16:31:21.032 > Nothing received, resend whole request
16:31:21.038 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:23.066 > RX Period End
16:31:23.270 > All missing
16:31:23.307 > Nothing received, resend whole request
16:31:23.315 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:23.886 > [DPL::announceStatus] waiting for a start/stop/restart/limit command to complete
16:31:25.114 > RX Period End
16:31:25.123 > All missing
16:31:25.131 > Nothing received, resend count exeeded
16:31:25.136 > Fetch inverter: 114485010664
16:31:25.146 > Resend ActivePowerControl
16:31:25.157 > Resend PowerCommand
16:31:25.269 > Interrupt received
16:31:25.277 > TX RealTimeRunData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 0B 00 67 7D 48 CC 00 00 00 00 00 00 00 00 D7 C3 66 
16:31:25.283 > Frame kaputt
16:31:25.831 > RX Period End
16:31:25.839 > All missing
16:31:25.843 > Nothing received, resend whole request
16:31:25.847 > TX RealTimeRunData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 0B 00 67 7D 48 CC 00 00 00 00 00 00 00 00 D7 C3 66 
16:31:26.445 > RX Period End
16:31:26.483 > All missing
16:31:26.491 > Nothing received, resend whole request
16:31:26.495 > TX RealTimeRunData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 0B 00 67 7D 48 CC 00 00 00 00 00 00 00 00 D7 C3 66 
16:31:26.960 > RX Period End
16:31:27.001 > All missing
16:31:27.009 > Nothing received, resend whole request
16:31:27.017 > TX RealTimeRunData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 0B 00 67 7D 48 CC 00 00 00 00 00 00 00 00 D7 C3 66 
16:31:27.471 > RX Period End
16:31:27.477 > All missing
16:31:27.483 > Nothing received, resend whole request
16:31:27.491 > TX RealTimeRunData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 0B 00 67 7D 48 CC 00 00 00 00 00 00 00 00 D7 C3 66 
16:31:27.982 > RX Period End
16:31:27.988 > All missing
16:31:27.993 > Nothing received, resend count exeeded
16:31:28.000 > TX AlarmData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 11 00 67 7D 48 CC 00 00 00 00 00 00 00 00 0D D8 BD 
16:31:28.801 > RX Period End
16:31:28.809 > All missing
16:31:28.812 > Nothing received, resend whole request
16:31:28.820 > TX AlarmData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 11 00 67 7D 48 CC 00 00 00 00 00 00 00 00 0D D8 BD 
16:31:29.621 > RX Period End
16:31:29.657 > All missing
16:31:29.663 > Nothing received, resend whole request
16:31:29.669 > TX AlarmData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 11 00 67 7D 48 CC 00 00 00 00 00 00 00 00 0D D8 BD 
16:31:30.132 > Interrupt received
16:31:30.170 > Frame kaputt
16:31:30.356 > RX Period End
16:31:30.363 > All missing
16:31:30.369 > Nothing received, resend whole request
16:31:30.376 > TX AlarmData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 11 00 67 7D 48 CC 00 00 00 00 00 00 00 00 0D D8 BD 
16:31:31.161 > RX Period End
16:31:31.168 > All missing
16:31:31.174 > Nothing received, resend whole request
16:31:31.183 > TX AlarmData 865.00 MHz --> 15 85 01 06 64 80 15 81 80 80 11 00 67 7D 48 CC 00 00 00 00 00 00 00 00 0D D8 BD 
16:31:31.975 > RX Period End
16:31:31.985 > All missing
16:31:31.992 > Nothing received, resend count exeeded
16:31:32.139 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:33.920 > [DPL inverter 114485010664]: timeout (19 in succession), state transition pending: yes, limit pending: yes
16:31:33.959 > [DPL inverter 114485010664]: issuing restart command after update timed out repeatedly
16:31:33.966 > [DPL::announceStatus] reloading DPL configuration
16:31:33.972 > [DPL::announceStatus] waiting for a start/stop/restart/limit command to complete
16:31:34.176 > RX Period End
16:31:34.182 > All missing
16:31:34.189 > Nothing received, resend whole request
16:31:34.196 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:36.214 > RX Period End
16:31:36.228 > All missing
16:31:36.231 > Nothing received, resend whole request
16:31:36.235 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:38.246 > RX Period End
16:31:38.255 > All missing
16:31:38.259 > Nothing received, resend whole request
16:31:38.265 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:40.167 > Interrupt received
16:31:40.205 > Frame kaputt
16:31:40.279 > RX Period End
16:31:40.287 > All missing
16:31:40.293 > Nothing received, resend whole request
16:31:40.302 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:31:42.289 > RX Period End
16:31:42.300 > All missing
16:31:42.309 > Nothing received, resend count exeeded
16:31:42.316 > [DPL inverter 114485010664]: sending limit of 2.5 % (20 W respectively), max output is 800 W
16:31:42.521 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:43.955 > [DPL::announceStatus] waiting for a start/stop/restart/limit command to complete
16:31:44.570 > RX Period End
16:31:44.580 > All missing
16:31:44.587 > Nothing received, resend whole request
16:31:44.594 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:46.619 > RX Period End
16:31:46.628 > All missing
16:31:46.632 > Nothing received, resend whole request
16:31:46.638 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:48.666 > RX Period End
16:31:48.705 > All missing
16:31:48.713 > Nothing received, resend whole request
16:31:48.722 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:50.652 > RX Period End
16:31:50.658 > All missing
16:31:50.670 > Nothing received, resend whole request
16:31:50.673 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:52.764 > RX Period End
16:31:52.773 > All missing
16:31:52.783 > Nothing received, resend count exeeded
16:31:52.935 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:53.852 > [DPL::announceStatus] waiting for a start/stop/restart/limit command to complete
16:31:54.967 > RX Period End
16:31:54.979 > All missing
16:31:54.984 > Nothing received, resend whole request
16:31:54.990 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:55.323 > Interrupt received
16:31:55.328 > Frame kaputt
16:31:57.065 > RX Period End
16:31:57.102 > All missing
16:31:57.111 > Nothing received, resend whole request
16:31:57.117 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:31:59.113 > RX Period End
16:31:59.149 > All missing
16:31:59.157 > Nothing received, resend whole request
16:31:59.163 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:32:01.159 > RX Period End
16:32:01.197 > All missing
16:32:01.205 > Nothing received, resend whole request
16:32:01.212 > TX PowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 02 00 D0 00 70 
16:32:03.107 > RX Period End
16:32:03.120 > All missing
16:32:03.126 > Nothing received, resend count exeeded
16:32:03.308 > TX ActivePowerControl 865.00 MHz --> 51 85 01 06 64 80 15 81 80 81 0B 00 00 19 00 01 67 11 C7 
16:32:03.930 > [DPL inverter 114485010664]: timeout (20 in succession), state transition pending: yes, limit pending: yes
16:32:03.962 > [DPL inverter 114485010664]: issuing restart command after update timed out repeatedly
16:32:03.970 > [DPL inverter 114485010664]: restarting system since inverter is unresponsive
16:32:03.977 > [DPL::announceStatus] reloading DPL configuration
16:32:03.984 > [DPL::announceStatus] waiting for a start/stop/restart/limit command to complete

Anything else?

No response

Please confirm the following

• I believe this issue is a bug that affects all users of OpenDTU-OnBattery, not something specific to my installation.
• I have already searched for relevant existing issues and discussions before opening this report.
• I have updated the title field above with a concise description.
• I have double checked that my inverter does not contain a W in the model name (like HMS-xxxW) as they are not supported.

[spcqike]

Du scheinst ein Kommunikationsproblem zum wechselrichter zu haben.

[kutzera]

Vielen Dank für die Antwort. Bis zur aktuellen Version hat die Kommunikation aber reibungslos funktioniert. Ich bin wieder zurück zur Version 2024.10.22 gewechselt und da geht alles wieder

[AndreasBoehm]

@kutzera kannst du ein Log anfertigen mit Version 2024.10.22?
Und wie lange hast du die Version 2024.11.20 laufen lassen bevor du zu dem Entschluss gekommen bist das sie nicht funktioniert?

[schlimmchen]

[DPL::announceStatus] waiting for a start/stop/restart/limit command to complete

Das ist aber merkwürdig, dass das in 2024.10.22 nicht auftritt sondern erst in 2024.11.20. Ich hab nicht im Detail auf dem Schirm, welche Änderungen es Upstream gab, die hier vielleicht eine Rolle spielen. Jedenfalls gab es zwar umfangreiche Änderungen am DPL, aber die Kommunikation mit den WR hat sich ja nicht stark verändert.

16:31:34.182 > All missing
16:31:34.189 > Nothing received, resend whole request

Da scheint ja gar nichts mehr zu klappen, du siehst auch keine Statistikupdates vom Inverter mehr und der Inverter wird im Web UI rot, stimmt's?

[Tobiasp1983]

Ich habe das gleiche mit der aktuellen bricht immer wieder die verbindung ab mit der Version 2024.10.22 läuft es ohne Probleme

[spcqike]

Vielleicht ist es ja dieses übergeordnete Problem mit der Kommunikation zu den HMS? Ich hab schon seit vielen Versionen gelegentlich Probleme. Mal mehr, mal weniger.

Ich hab die Frequenz auf 869MHz geändert, damit läuft es eigentlich stabil.

Dennoch ist es mir letztens auch mit der 2024.11.20 passiert, dass der HMS-2000 ab einer gewissen Leistung nicht mehr erreicht wurde. (ich meine es war, als die Leistung so um 600W und mehr hatte)
Bei mir hat es, wie immer, gereicht, die "DTU Settings" erneut zu speichern (ohne etwas an meinen Einstellungen zu ändern)

Der WR war sofort wieder erreichbar und es lief stabil durch.

@schlimmchen ich hab dir dieses Verhalten ja schon mal per Mail geschildert, auch hab ich es im Upstream hier und da gefunden.

Wie gesagt, keine Ahnung ob es bei euch genau das ist, aber wenn es das ist, suchen wir hier im Release bzw den Änderungen wahrscheinlich an der falschen Stelle.

[Tobiasp1983]

ich habe den HMS 1200. Ich habe es getestet, die Leitung vom WR spielt keine Rolle.

[kutzera]

Bei mir setzt er komischerweise am Abend aus, wenn er Steuern soll. Der DPL des HMS-2000-4T bleibt bei mir seltsamerweise bei 206W stecken und dann ist er nicht mehr erreichbar.

[kutzera]

Ich packe nochmal meinen aktuellen log dazu irgendwie bleibt er bei der Steuerung stecken...es sind aber nicht 206W sondern 260W

Websocket: [/livedata][13] disconnect
15:29:05.067 > Fetch inverter: 116491959108
15:29:05.579 > Success
15:29:06.093 > [DPL::announceStatus] the system is stable, the last power limit is still valid
15:29:07.012 > Fetch inverter: 116491954386
15:29:07.627 > Success
15:29:09.060 > Fetch inverter: 116481313573
15:29:09.549 > Success
15:29:11.008 > Fetch inverter: 114485010664
15:29:11.621 > Success
15:29:13.054 > Fetch inverter: 116491958590
15:29:13.567 > Success
15:29:15.102 > Fetch inverter: 116491959108
15:29:15.616 > Success
15:29:16.024 > [DPL::announceStatus] the system is stable, the last power limit is still valid
15:29:17.048 > Fetch inverter: 116491954386
15:29:17.663 > All missing
15:29:17.690 > Nothing received, resend whole request
15:29:18.174 > Success
15:29:19.096 > Fetch inverter: 116481313573
15:29:19.558 > Success
15:29:21.011 > Fetch inverter: 114485010664
15:29:21.655 > Success
15:29:23.012 > Fetch inverter: 116491958590
15:29:23.603 > Success
15:29:25.014 > Fetch inverter: 116491959108
15:29:25.651 > Success
15:29:26.060 > [DPL::announceStatus] the system is stable, the last power limit is still valid
15:29:27.018 > Fetch inverter: 116491954386
15:29:27.595 > Success
15:29:29.028 > Fetch inverter: 116481313573
15:29:29.566 > Success
15:29:31.076 > Fetch inverter: 114485010664
15:29:31.588 > Success
15:29:33.124 > Fetch inverter: 116491958590
15:29:33.637 > Success
15:29:35.021 > Fetch inverter: 116491959108
15:29:35.582 > Success
15:29:36.095 > [DPL::announceStatus] the system is stable, the last power limit is still valid
15:29:37.022 > Fetch inverter: 116491954386
15:29:37.630 > Success
15:29:39.064 > Fetch inverter: 116481313573
15:29:39.571 > Success
15:29:41.025 > Fetch inverter: 114485010664
15:29:41.624 > Success
15:29:43.027 > Fetch inverter: 116491958590
15:29:43.672 > Success
15:29:45.041 > Fetch inverter: 116491959108
15:29:45.720 > All missing
15:29:45.746 > Nothing received, resend whole request
15:29:46.026 > [DPL::announceStatus] the system is stable, the last power limit is still valid
15:29:46.144 > Success
15:29:47.029 > Fetch inverter: 116491954386
15:29:47.036 > Request SystemConfigPara
15:29:47.666 > Success
15:29:47.870 > FATAL: (lib/Hoymiles/src/parser/SystemConfigParaParser.cpp, 38) stats packet too large for buffer
15:29:47.895 > FATAL: (lib/Hoymiles/src/parser/SystemConfigParaParser.cpp, 38) stats packet too large for buffer
15:29:47.903 > Success
15:29:49.031 > Fetch inverter: 116481313573
15:29:49.580 > Success
15:29:51.033 > Fetch inverter: 114485010664
15:29:51.042 > Request SystemConfigPara
15:29:51.581 > Success
15:29:52.273 > Success
15:29:53.076 > Fetch inverter: 116491958590
15:29:53.606 > Success
15:29:55.086 > Fetch inverter: 116491959108
15:29:55.656 > All missing
15:29:55.663 > Nothing received, resend whole request
15:29:56.024 > [DPL::announceStatus] the system is stable, the last power limit is still valid
15:29:56.268 > All missing
15:29:56.294 > Nothing received, resend whole request
15:29:56.780 > All missing
15:29:56.805 > Nothing received, resend whole request
15:29:57.239 > All missing
15:29:57.246 > Nothing received, resend whole request
15:29:57.803 > All missing
15:29:57.814 > Nothing received, resend count exeeded
15:29:57.829 > Fetch inverter: 116491954386
15:29:58.623 > Success
15:29:59.852 > Fetch inverter: 116481313573
15:30:00.290 > Success

[Tobiasp1983]

Ich habe es mal getestet die settings komplett "neu" einzugeben und zu speichern. Auch hier dieselben Probleme. Er hat massiv Kommunikationsprobleme und im Webui ist er mit der aktuellen Software mehr rot als Blau. Was ist mit der Version von gestern, die habe ich noch nicht getestet. Wurde hier was geändert?

[Manos1966]

Minimum Wechselrichter Limit (beim HMS1600?) auf 20W? 😱

[schlimmchen]

Minimum Wechselrichter Limit (beim HMS1600?) auf 20W? 😱

@Manos1966 Wo siehst du das? @kutzera Wenn das zutreffend ist, musst du dein minimales Leistungslimit bitte hochsetzen.

15:29:47.870 > FATAL: (lib/Hoymiles/src/parser/SystemConfigParaParser.cpp, 38) stats packet too large for buffer

Das hab ich vorhin schon woanders auch mal gesehen. Merkwürdig, das ist neu.

@kutzera Bei deinem letzten Log ist aber die Kommunikation mit dem WR scheinbar in Ordnung und der DPL entscheidet, dass das Limit nicht angepasst werden muss, weil es keine Änderung gab. Das ist dann aber eine andere Sache. Kann es sein, dass du verbose logging ausgeschaltet hast? Mach das mal bitte an, dann sehen wir auch mehr im Log, insb. warum der DPL entscheidet, dass nichts zu tun sei.