Mosibi / Midea-heat-pump-ESPHome

Apache License 2.0
43 stars 10 forks source link

spontantious reboots, CRC error and esp turning off, #33

Closed bkbartk closed 1 week ago

bkbartk commented 1 week ago

I must be doing someting wrong but I can't figure what it is. I use the module from SVEN. including the cable. And today I finally had the time to install it,

On my device connectors X and E are swapped, So I still connect to E.

My esp device spontaneously reboots sometimes, and sometimes completely becomes unavailable until I repower the espmodule. Also In the log I see CRC errors anw when I'm able to change a setting a lot of times it will be reverted. I added reset reason to the script, but now the device is completely unavailable with this in the log.

INFO Upload took 12.68 seconds, waiting for result...
INFO OTA successful
INFO Successfully uploaded program.
INFO Starting log output from 192.168.170.196 using esphome API
INFO Successfully connected to heatpump @ 192.168.170.196 in 11.274s
INFO Successful handshake with heatpump @ 192.168.170.196 in 0.110s
[19:41:31][I][app:100]: ESPHome version 2024.8.3 compiled on Sep  7 2024, 19:39:51
[19:41:33][W][component:237]: Component modbus_controller took a long time for an operation (113 ms).
[19:41:33][W][component:238]: Components should block for at most 30 ms.
[19:41:33][W][component:237]: Component modbus_controller took a long time for an operation (103 ms).
[19:41:33][W][component:238]: Components should block for at most 30 ms.
[19:41:33][W][component:237]: Component modbus_controller took a long time for an operation (86 ms).
[19:41:33][W][component:238]: Components should block for at most 30 ms.
[19:41:42][W][component:237]: Component modbus_controller took a long time for an operation (85 ms).
[19:41:42][W][component:238]: Components should block for at most 30 ms.
[19:41:43][W][component:237]: Component modbus_controller took a long time for an operation (293 ms).
[19:41:43][W][component:238]: Components should block for at most 30 ms.
[19:41:43][W][component:237]: Component modbus_controller took a long time for an operation (233 ms).
[19:41:44][W][component:237]: Component modbus_controller took a long time for an operation (513 ms).
[19:41:46][W][modbus:114]: Modbus CRC Check failed! 371!=7571
[19:41:49][W][modbus:114]: Modbus CRC Check failed! DD09!=7565
[19:41:52][W][component:237]: Component modbus_controller took a long time for an operation (78 ms).
[19:41:55][W][component:237]: Component modbus_controller took a long time for an operation (218 ms).
[19:41:56][W][component:237]: Component modbus_controller took a long time for an operation (497 ms).
[19:42:02][W][component:237]: Component modbus_controller took a long time for an operation (89 ms).
[19:42:02][W][component:238]: Components should block for at most 30 ms.
[19:42:03][W][component:237]: Component modbus_controller took a long time for an operation (253 ms).
[19:42:06][W][component:238]: Components should block for at most 30 ms.
[19:42:12][W][component:237]: Component modbus_controller took a long time for an operation (75 ms).
[19:42:13][W][component:237]: Component modbus_controller took a long time for an operation (219 ms).
[19:42:18][W][modbus:114]: Modbus CRC Check failed! 8897!=6173
[19:42:20][I][safe_mode:041]: Boot seems successful; resetting boot loop counter
[19:42:22][W][component:237]: Component modbus_controller took a long time for an operation (74 ms).
[19:42:23][W][component:237]: Component modbus_controller took a long time for an operation (532 ms).
[19:42:28][W][component:237]: Component modbus_controller took a long time for an operation (532 ms).
[19:42:32][W][component:237]: Component modbus_controller took a long time for an operation (82 ms).
[19:42:32][W][component:238]: Components should block for at most 30 ms.
[19:42:36][W][component:237]: Component modbus_controller took a long time for an operation (207 ms).
[19:42:42][W][component:237]: Component modbus_controller took a long time for an operation (89 ms).
[19:42:42][W][component:238]: Components should block for at most 30 ms.
[19:42:45][W][component:237]: Component modbus_controller took a long time for an operation (468 ms).
[19:42:46][W][component:237]: Component modbus_controller took a long time for an operation (345 ms).
[19:42:52][W][component:237]: Component modbus_controller took a long time for an operation (81 ms).
[19:42:52][W][component:238]: Components should block for at most 30 ms.
[19:42:53][W][component:237]: Component modbus_controller took a long time for an operation (421 ms).
[19:42:55][W][component:238]: Components should block for at most 30 ms.
[19:42:56][W][component:237]: Component modbus_controller took a long time for an operation (219 ms).
[19:43:02][W][component:237]: Component modbus_controller took a long time for an operation (82 ms).
[19:43:02][W][component:238]: Components should block for at most 30 ms.
[19:43:06][W][component:237]: Component modbus_controller took a long time for an operation (515 ms).
[19:43:12][W][component:237]: Component modbus_controller took a long time for an operation (934 ms).
[19:43:19][W][component:237]: Component modbus_controller took a long time for an operation (61 ms).
[19:43:19][W][component:237]: Component modbus_controller took a long time for an operation (1147 ms).
[19:43:19][W][component:238]: Components should block for at most 30 ms.
[19:43:19][W][modbus:114]: Modbus CRC Check failed! 8897!=6173
[19:43:19][I][zone1_h_emission:137]: Set option to Underfloor Heating (2)
[19:43:19][W][component:237]: Component modbus_controller took a long time for an operation (99 ms).
[19:43:19][W][component:238]: Components should block for at most 30 ms.
[19:43:22][W][component:237]: Component modbus_controller took a long time for an operation (89 ms).
[19:43:22][W][component:238]: Components should block for at most 30 ms.
[19:43:27][W][component:237]: Component modbus_controller took a long time for an operation (221 ms).
WARNING heatpump @ 192.168.170.196: Connection error occurred: [Errno 104] Connection reset by peer
INFO Processing unexpected disconnect from ESPHome API for heatpump @ 192.168.170.196
WARNING Disconnected from API
INFO Successfully connected to heatpump @ 192.168.170.196 in 0.007s
WARNING heatpump @ 192.168.170.196: Connection error occurred: heatpump @ 192.168.170.196: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (ESPHome Logs 2024.8.3).
WARNING Can't connect to ESPHome API for heatpump @ 192.168.170.196: heatpump @ 192.168.170.196: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (ESPHome Logs 2024.8.3). (HandshakeAPIError)
INFO Trying to connect to heatpump @ 192.168.170.196 in the background
INFO Successfully connected to heatpump @ 192.168.170.196 in 0.015s
WARNING heatpump @ 192.168.170.196: Connection error occurred: heatpump @ 192.168.170.196: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (ESPHome Logs 2024.8.3).
INFO Successfully connected to heatpump @ 192.168.170.196 in 0.006s
WARNING heatpump @ 192.168.170.196: Connection error occurred: heatpump @ 192.168.170.196: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (ESPHome Logs 2024.8.3).
INFO Successfully connected to heatpump @ 192.168.170.196 in 3.177s
INFO Successful handshake with heatpump @ 192.168.170.196 in 0.109s
[19:44:32][W][component:237]: Component modbus_controller took a long time for an operation (111 ms).
[19:44:32][W][component:238]: Components should block for at most 30 ms.
[19:44:33][W][component:237]: Component modbus_controller took a long time for an operation (115 ms).
[19:44:33][W][component:238]: Components should block for at most 30 ms.
[19:44:33][W][component:237]: Component modbus_controller took a long time for an operation (66 ms).
[19:44:33][W][component:238]: Components should block for at most 30 ms.
[19:44:42][W][component:237]: Component modbus_controller took a long time for an operation (89 ms).
[19:44:42][W][component:238]: Components should block for at most 30 ms.
[19:44:44][W][component:237]: Component modbus_controller took a long time for an operation (282 ms).
[19:44:45][W][component:237]: Component modbus_controller took a long time for an operation (138 ms).
[19:44:47][W][component:237]: Component modbus_controller took a long time for an operation (82 ms).
[19:44:49][W][modbus_controller:065]: Modbus device=1 back online
[19:44:53][W][modbus:114]: Modbus CRC Check failed! 93F9!=6567
[19:45:07][W][component:237]: Component modbus_controller took a long time for an operation (1114 ms).
WARNING heatpump @ 192.168.170.196: Connection error occurred: [Errno 104] Connection reset by peer
INFO Processing unexpected disconnect from ESPHome API for heatpump @ 192.168.170.196
WARNING Disconnected from API
WARNING Can't connect to ESPHome API for heatpump @ 192.168.170.196: Error connecting to [AddrInfo(family=<AddressFamily.AF_INET: 2>, type=<SocketKind.SOCK_STREAM: 1>, proto=6, sockaddr=IPv4Sockaddr(address='192.168.170.196', port=6053))]: [Errno 111] Connect call failed ('192.168.170.196', 6053) (SocketAPIError)
INFO Trying to connect to heatpump @ 192.168.170.196 in the background
INFO Successfully connected to heatpump @ 192.168.170.196 in 0.013s
INFO Successful handshake with heatpump @ 192.168.170.196 in 0.127s
[19:46:02][W][component:237]: Component modbus_controller took a long time for an operation (54 ms).
[19:46:02][W][component:238]: Components should block for at most 30 ms.
[19:46:11][W][component:237]: Component modbus_controller took a long time for an operation (87 ms).
[19:46:11][W][component:238]: Components should block for at most 30 ms.
[19:46:12][W][component:237]: Component modbus_controller took a long time for an operation (61 ms).
[19:46:12][W][component:238]: Components should block for at most 30 ms.
[19:46:12][W][component:237]: Component modbus_controller took a long time for an operation (85 ms).
[19:46:12][W][component:238]: Components should block for at most 30 ms.
[19:46:18][W][modbus:114]: Modbus CRC Check failed! 8897!=6173
[19:46:18][W][modbus:114]: Modbus CRC Check failed! 63D3!=7365
[19:46:28][W][modbus:114]: Modbus CRC Check failed! 93F9!=6567
[19:46:28][W][modbus:114]: Modbus CRC Check failed! 8897!=6173
[19:46:49][W][component:237]: Component modbus_controller took a long time for an operation (75 ms).
WARNING heatpump @ 192.168.170.196: Connection error occurred: Ping response not received after 90.0 seconds
INFO Processing unexpected disconnect from ESPHome API for heatpump @ 192.168.170.196
WARNING Disconnected from API
WARNING Can't connect to ESPHome API for heatpump @ 192.168.170.196: Error connecting to [AddrInfo(family=<AddressFamily.AF_INET: 2>, type=<SocketKind.SOCK_STREAM: 1>, proto=6, sockaddr=IPv4Sockaddr(address='192.168.170.196', port=6053))]: [Errno 113] Connect call failed ('192.168.170.196', 6053) (SocketAPIError)
INFO Trying to connect to heatpump @ 192.168.170.196 in the background

I think about maybe a power issue, but that still doesn't explain the Modbus CRC Check failed! errors. of maybe, there are just to many sensors for ESP32 arduino and it's better to flash to ESP-IDF, but then I wouldn't be the only one having this issue.

Mosibi commented 1 week ago

Hi, for support on the hardware controller you can create a ticket on https://shop.svenar.nl/support/ or sent an email to support@svenar.nl so that would will receive the support you need.

bkbartk commented 1 week ago

thanks, I asked the question over there, and I know this one is closed, but now think the issue is memory related I added heapsize to sensors and I found the following, what happens is,

  1. there is no error in the logs
  2. I make a change which causes an error 22:30:19 [E] [modbus_controller:101] Modbus error - last command: function code=0x6 register address = 0x2 registers count=1 payload size=2
  3. the esp suddenly consumes a lot of memory, making it crash. image (red circle is the moment of crashing) I know from other project that when the heapsize approaches 60.000 it probably will crash, however it didn't crash 5 minutes later.
  4. then after the first crash for some reason CRC errors start occurring and it crashes some more (while memory is not evne near 60.000) until it dies. see uptime sensor image number 4 is the strangest,

If I find the time I will serial flash with esp-idf because that one manages the memory better.

bkbartk commented 1 week ago

ok, just maybe for someones info,

I flashed with ESP-IDF, and then I applied the action which made the device crash earlier, tried this 3 times.

Still I got an error in the log, probably my device uses some different adress somewhere. but the free heap didn't decrease, also there is no reboot, and no CRC errors afterwards image probably esphome arduino doesn't handle errors as nicely which causes the problem.

So that one is fixed, Now I have to dive into the other issues I have.

Mosibi commented 1 week ago

@bkbartk goed to read that you solved this issue. Can you share which action(s) you exactly executed to get the behavior? Until now we (Sven) are not able to reproduce the issue you see.

bkbartk commented 1 week ago

what I do is the following, I grep the slider for the entering temperature number.heatpump_set_water_temperature_t1s_zone_1 and lower it's value. image then I get this error in the esplog

19:30:22    [W] [component:237] Component modbus_controller took a long time for an operation (215 ms).
19:30:22    [W] [component:238] Components should block for at most 30 ms.
19:30:23    [W] [component:237] Component modbus_controller took a long time for an operation (201 ms).
19:30:23    [W] [component:238] Components should block for at most 30 ms.
19:30:24    [E] [modbus_controller:092] Modbus error function code: 0x6 exception: 3 
19:30:24    [E] [modbus_controller:101] Modbus error - last command: function code=0x6  register address = 0x2  registers count=1 payload size=2
19:30:32    [W] [component:237] Component modbus_controller took a long time for an operation (66 ms).
19:30:32    [W] [component:238] Components should block for at most 30 ms.
19:30:32    [W] [component:237] Component modbus_controller took a long time for an operation (213 m

and the value won't change/is reverted after a refresh

the value changes during the day, and represents the number shown on the Midea terminal. what I think is that this value represents the actual temperature instead of the desired water temperature.

The device I have is a "Midea monoblock 6KW"

Mosibi commented 1 week ago

The modbus registers I could find, are consistent with the generic configuration. I see that the text in your screenshot shows “entering temperature”, I assume that is from a custom dashboard, since the default text is different.

Can you share the exact Heatpump model that you have, maybe with that information I am able to find an other modbus register list.

bkbartk commented 1 week ago

I use the dashboard from github https://github.com/Mosibi/Midea-heat-pump-ESPHome/tree/master/homeassistant but it is number.heatpump_set_water_temperature_t1s_zone_1 as at the moment, I'm not sure yet what I need.

The value 30, is consistent with the "Water flow desired temperature" so that's good, yesterday it was 55, So I thought it was the actual temp, but the manual mentions "desired", not sure why it changes over time.

I don't know the exact model number, can this be "MHC-V6W/D2N8-BE30"? this is in the documentation,

And my controller has model number: KJRH-120F/BMKO-E I see there is a full modbus spec in the manual but for somehow it's left out of the online manual.

It says

Register address: 2(PLC: 40003)

Description: Setting water water temperature T1S

Remarks:
Bit8-Bit15 Water temperature T1s is corresponding to the floor heating.(zone 2)
Bit0-Bit7 Water temperature T1s is corresponding to the floor heating.(zone 1)

Edit: I can change other options image so at least write works as expected

Edit2: And this is interesting, This issue only occurs if I try to set a value <26, I can just set 28 without any issues.

Mosibi commented 1 week ago

Do you have weather compensation on or off for zone 1? Looking at my own stats, I see that the register seems to work like a sensor, thus reporting the current value, when weather compensation is off.

bkbartk commented 1 week ago

yes it's off for both zones image and when I try to enable it, it automatically turns off again, so probably I'm not allowed to change that one.

Mosibi commented 1 week ago

It could be that you can’t enable weather compensation when it is in “thermostat” mode, but I am not sure about that.

bkbartk commented 1 week ago

thank you for spending time on this one,

later Weather compensation was enabled, still 25 was the minimum value I could select, I think it might takes some time before the modbus reacts on changes.

However for my this is more like a theoretical issue then an actual one since my ESP doesn't crash anymore. when heating the temperature should never be below 25 so that's ok. and my cooling conditions aren't in place yet.

if you want me to apply some tests I'd be happy to do so, but if this is just for me you don't need to put any effort in it.