Echonet Lite disconnecting sporadically until restart

[16thompn]

Good morning

I have been having this issue with my Mistsubishi Electric MSZ AP25/70 Aircon units since March and have tried numerous things to solve the problem.

After restarting home assistant, the aircons connect successfully and will maintain a connection anywhere from a few hours to several days before they become unavailable in home assistant and will not reconnect until the home assistant system is restarted. They still remain connected through the Mitsubishi App as well as through Google Home. They were running without issue for about 18 months before this issue began. I had not updated or changed anything on my homeassistant OS in about 6 months. Since then, I have updated to the latest version of echonet as well as updated the homeassistant core and homeassistant OS.

I have ensured that my router keeps these aircons on a static IP so that should not be the issue. I have enabled the debug log and posted the results below. You can see it is working normally before it seemingly begins timing out and will not reconnect. I'm not sure if this is an issue with the integration or my own personal setup. I have tried deleting and re-adding the devices since updating to the latest version of echonet. Any help would be greatly appreciated as I love the integration and use it everyday.

Please let me know if you need any more info. The debug log was 40mb as I enabled it immediately after restarting and it took three days before the latest disconnection issue so have included just the snippet below.

Cheers Nick

2024-04-30 11:54:42.140 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.office_aircon is taking over 10 seconds
2024-04-30 11:54:42.151 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.kitchen_aircon is taking over 10 seconds
2024-04-30 11:54:42.151 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.rumpus_aircon is taking over 10 seconds
2024-04-30 11:54:42.179 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.bedroom_aircon is taking over 10 seconds
2024-04-30 11:55:02.494 DEBUG (MainThread) [custom_components.echonetlite] 
ECHONETlite polling update data:
 - Operation status 0x80(128): off
 - Air flow rate setting 0xa0(160): auto
 - Automatic control of air flow direction setting 0xa1(161): non-auto
 - Automatic swing of air flow setting 0xa3(163): not-used
 - Air flow direction (vertical) setting 0xa4(164): upper
 - Air flow direction (horizontal) setting 0xa5(165): right
 - Operation mode setting 0xb0(176): cool
 - Set temperature value 0xb3(179): 23
 - Measured value of room temperature 0xbb(187): 26
 - Measured outdoor air temperature 0xbe(190): 126

2024-04-30 11:55:02.495 DEBUG (MainThread) [custom_components.echonetlite.climate] Called async_update_callback on Office Aircon.
Changed: True
Update data: {128: 'off', 160: 'auto', 161: 'non-auto', 163: 'not-used', 164: 'upper', 165: 'right', 176: 'cool', 179: 23, 187: 26, 190: 126}
Old data: {128: 'off', 160: 'auto', 161: 'non-auto', 163: 'not-used', 164: 'upper', 165: 'right', 176: 'cool', 179: 23, 187: 26, 190: 126}
2024-04-30 11:55:02.505 DEBUG (MainThread) [custom_components.echonetlite] 
ECHONETlite polling update data:
 - Operation status 0x80(128): off
 - Air flow rate setting 0xa0(160): auto
 - Automatic control of air flow direction setting 0xa1(161): non-auto
 - Automatic swing of air flow setting 0xa3(163): not-used
 - Air flow direction (vertical) setting 0xa4(164): upper
 - Air flow direction (horizontal) setting 0xa5(165): left
 - Operation mode setting 0xb0(176): cool
 - Set temperature value 0xb3(179): 20
 - Measured value of room temperature 0xbb(187): 23
 - Measured outdoor air temperature 0xbe(190): 126

2024-04-30 11:55:02.506 DEBUG (MainThread) [custom_components.echonetlite.climate] Called async_update_callback on Kitchen Aircon.
Changed: True
Update data: {128: 'off', 160: 'auto', 161: 'non-auto', 163: 'not-used', 164: 'upper', 165: 'left', 176: 'cool', 179: 20, 187: 23, 190: 126}
Old data: {128: 'off', 160: 'auto', 161: 'non-auto', 163: 'not-used', 164: 'upper', 165: 'left', 176: 'cool', 179: 20, 187: 23, 190: 126}
2024-04-30 11:55:02.611 DEBUG (MainThread) [custom_components.echonetlite] 
ECHONETlite polling update data:
 - Operation status 0x80(128): off
 - Automatic control of air flow direction setting 0xa1(161): non-auto
 - Air flow rate setting 0xa0(160): auto
 - Automatic swing of air flow setting 0xa3(163): not-used
 - Air flow direction (vertical) setting 0xa4(164): upper
 - Air flow direction (horizontal) setting 0xa5(165): right
 - Measured cumulative power consumption 0x85(133): 913700
 - Operation mode setting 0xb0(176): cool
 - Set temperature value 0xb3(179): 21
 - Measured value of room temperature 0xbb(187): 25
 - Measured outdoor air temperature 0xbe(190): 126

2024-04-30 11:55:02.612 DEBUG (MainThread) [custom_components.echonetlite.climate] Called async_update_callback on Rumpus Aircon.
Changed: True
Update data: {128: 'off', 161: 'non-auto', 160: 'auto', 163: 'not-used', 164: 'upper', 165: 'right', 133: 913700, 176: 'cool', 179: 21, 187: 25, 190: 126}
Old data: {128: 'off', 161: 'non-auto', 160: 'auto', 163: 'not-used', 164: 'upper', 165: 'right', 133: 913700, 176: 'cool', 179: 21, 187: 25, 190: 126}
2024-04-30 11:55:02.638 DEBUG (MainThread) [custom_components.echonetlite] 
ECHONETlite polling update data:
 - Operation status 0x80(128): off
 - Automatic control of air flow direction setting 0xa1(161): non-auto
 - Air flow rate setting 0xa0(160): auto
 - Automatic swing of air flow setting 0xa3(163): not-used
 - Air flow direction (vertical) setting 0xa4(164): lower
 - Air flow direction (horizontal) setting 0xa5(165): right
 - Measured cumulative power consumption 0x85(133): 321000
 - Operation mode setting 0xb0(176): cool
 - Set temperature value 0xb3(179): 18
 - Measured value of room temperature 0xbb(187): 23
 - Measured outdoor air temperature 0xbe(190): 126

2024-04-30 11:55:02.639 DEBUG (MainThread) [custom_components.echonetlite.climate] Called async_update_callback on Bedroom Aircon.
Changed: True
Update data: {128: 'off', 161: 'non-auto', 160: 'auto', 163: 'not-used', 164: 'lower', 165: 'right', 133: 321000, 176: 'cool', 179: 18, 187: 23, 190: 126}
Old data: {128: 'off', 161: 'non-auto', 160: 'auto', 163: 'not-used', 164: 'lower', 165: 'right', 133: 321000, 176: 'cool', 179: 18, 187: 23, 190: 126}
2024-04-30 11:55:12.796 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.office_aircon_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 11:55:12.800 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.kitchen_aircon_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 11:55:12.849 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.rumpus_aircon_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 11:55:12.867 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.bedroom_aircon_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 11:55:32.796 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 11:55:32.798 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 11:55:32.850 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 11:55:32.867 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 11:55:42.142 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.office_aircon is taking over 10 seconds
2024-04-30 11:55:42.154 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.kitchen_aircon is taking over 10 seconds
2024-04-30 11:55:42.154 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.rumpus_aircon is taking over 10 seconds
2024-04-30 11:55:42.182 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.bedroom_aircon is taking over 10 seconds`
2024-04-30 11:56:12.797 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.office_aircon_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 11:56:12.800 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.kitchen_aircon_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 11:56:12.857 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.rumpus_aircon_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 11:56:12.868 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.bedroom_aircon_automatic_control_of_air_flow_direction_setting is taking over 10 seconds

[jacobw]

I'm getting a similar issue. I've been trying to isolate the issue and found this issue. All of my heat pumps have the same issue, like the orig poster, the Mitsubishi app still works fine.

2024-04-30 02:14:28.705 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.may_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:14:28.706 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.sw2_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:14:28.889 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.main_bedroom_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:14:48.705 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:14:48.706 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:14:48.889 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:14:58.706 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.may_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:14:58.890 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.sw2_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:14:58.891 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.main_bedroom_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:15:18.706 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:15:18.890 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:15:18.891 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:15:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.may_heatpump is taking over 10 seconds
2024-04-30 02:15:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.sw2_heatpump is taking over 10 seconds
2024-04-30 02:15:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.main_bedroom_heatpump is taking over 10 seconds
2024-04-30 02:15:28.706 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.may_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:15:28.707 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.sw2_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:15:28.890 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.main_bedroom_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:15:48.706 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:15:48.707 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:15:48.890 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:15:58.708 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.may_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:15:58.890 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.sw2_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:15:58.892 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.main_bedroom_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:16:18.707 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:16:18.891 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:16:18.893 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:16:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.may_heatpump is taking over 10 seconds
2024-04-30 02:16:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.sw2_heatpump is taking over 10 seconds
2024-04-30 02:16:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.main_bedroom_heatpump is taking over 10 seconds
2024-04-30 02:16:28.707 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.may_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:16:28.709 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.sw2_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:16:28.892 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.main_bedroom_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:16:48.707 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:16:48.708 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:16:48.892 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:16:58.708 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.may_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:16:58.892 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.sw2_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:16:58.894 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.main_bedroom_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:17:18.709 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:17:18.892 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:17:18.894 WARNING (MainThread) [homeassistant.components.select] Updating echonetlite select took longer than the scheduled update interval 0:00:30
2024-04-30 02:17:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.may_heatpump is taking over 10 seconds
2024-04-30 02:17:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.sw2_heatpump is taking over 10 seconds
2024-04-30 02:17:23.016 WARNING (MainThread) [homeassistant.helpers.entity] Update of climate.main_bedroom_heatpump is taking over 10 seconds
2024-04-30 02:17:28.709 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.may_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:17:28.709 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.sw2_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:17:28.893 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.main_bedroom_heatpump_measured_cumulative_power_consumption is taking over 10 seconds
2024-04-30 02:17:48.709 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:17:48.710 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:17:48.894 WARNING (MainThread) [homeassistant.components.sensor] Updating echonetlite sensor took longer than the scheduled update interval 0:00:30
2024-04-30 02:17:58.710 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.may_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:17:58.894 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.sw2_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds
2024-04-30 02:17:58.895 WARNING (MainThread) [homeassistant.helpers.entity] Update of select.main_bedroom_heatpump_automatic_control_of_air_flow_direction_setting is taking over 10 seconds

[nao-pon]

This integration may be the cause, but we were unable to determine the problem from the log file. Please try the following measures to rule out any influence from the network environment.

1. Restart the LAN hub
2. Restart the network router
3. Power cycle the air conditioner

Continue to observe after taking the above measures.

[jacobw]

I've had to rollback as I can't have my home as a test environment overnight sorry. I can say that I'm a network engineer and it wasn't a network issue cause such significant delays observed over days. I also have 3 Mistsubishi heatpumps (2 x AP25 and 1 AP35) and they all had the issue at the same time, so I think that eliminates the heat pump being the issue.

I notice the orig poster has the same model heatpumps.

I'll try and roll forward during the day but not sure if it will be long enough to trigger it.

Are there some manual debug commands I can run to figure out what is causing the issue when it happens?

[scottyphillips]

@16thompn So if I understand this correctly - this issue started in March, but at the time you had not performed any sort of update of either home assistant or this component, having not updated in 6 months? Has anything else in your environment possibly changed?

Do you add the devices manually using their IP address, or do you use the auto discover function (which relies heavily on multicast?) Perhaps try enabling the force polling option too to see if that helps?

[scottyphillips]

I would be adding the devices manually using their IP address rather then auto discover if that is what is being used at this point. It could possibly be some issue with IGMP snooping killing off multicast queries after a certain period of time? I have had no end of dramas with IGMP snooping for similar integrations which rely on multicast?

[scottyphillips]

@jacobw as you are a network engineer, fire up Wireshark on a spare laptop and monitor the traffic over a period of time to see if you can identify what is going on?

[jacobw]

Does the autodiscover process not just get the ip and save it?

[16thompn]

@16thompn So if I understand this correctly - this issue started in March, but at the time you had not performed any sort of update of either home assistant or this component, having not updated in 6 months? Has anything else in your environment possibly changed?

Do you add the devices manually using their IP address, or do you use the auto discover function (which relies heavily on multicast?) Perhaps try enabling the force polling option too to see if that helps?

Apologies for the delay in getting back!

That's correct. The HomeAssistant version had not been touched for over 6 months (including not updating) and I also had not installed any new software or integrations or even added any new devices. Everything was working so didn't touch it! We have not changed routers or anything to do with the internet set up.

I manually locked the IP address of my HVAC systems in my router settings and then manually added the IP addresses to the EchoNet integration. This worked rather flawlessly for about 18 months.

Since this I have tried restarting the router and lan hub, HA, power cycles the aircons and readd them again. It works for several days but still disconnects shortly after.

I have actually added a restart HA button to my interface as a temporary measure and this works a treat as they will always be reconnected when the system reboots

Let me know if I can provide any more information or if there are any other debugging logs that I could access to shed more light on the issue.

Cheers Nick

[scottyphillips]

@16thompn To be frank it is difficult for me to attribute your issues to any fault in the custom component. As you said - you hadn't updated anything, it worked flawlessly for 6 months and then you started encountering issues. Your issue cannot have been caused by some issue with the custom component since it was working for 6 months. 6 months of issue free performance is hardly indicative of any undetected defect in the code. If you had said you updated to version X of either Home assistant and/or the custom component, and then the issues started there would be a clear causality and we could look at what changed in the code or not. But in your case we cannot. How exactly are you running Home Assistant? Unfortunately I do not have the time available to work on this. The only thing I suggest at this stage is to roll back to version 1.7.9 as there have been some significant updates in 1.8.0.

[16thompn]

I am running HA on a Raspberry Pi 4. The integration has now been working without issue for 72 hours since the last restart. I appreciate your feedback and if I continue to have it drop out I will try rolling back. It does make sense that something else might be going wrong given that it worked without issue for so long. I just can't work out what that might be given the lack of any changes to the system! I will update if I find any more useful info.

My only thought is that if the request is timing out, is there a way to increase this? Can I do this manually anywhere?

Thanks again