ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._read_ready()

[slivorezka]

System Health details

System Information

version	core-2024.4.0
installation_type	Home Assistant OS
dev	false
hassio	true
docker	true
user	root
virtualenv	false
python_version	3.12.2
os_name	Linux
os_version	6.6.16-haos
arch	x86_64
timezone	Europe/Kyiv
config_dir	/config

Home Assistant Community Store

GitHub API	ok
GitHub Content	ok
GitHub Web	ok
GitHub API Calls Remaining	5000
Installed Version	1.34.0
Stage	running
Available Repositories	1400
Downloaded Repositories	7

Home Assistant Cloud

logged_in	false
can_reach_cert_server	ok
can_reach_cloud_auth	ok
can_reach_cloud	ok

Home Assistant Supervisor

host_os	Home Assistant OS 12.0
update_channel	stable
supervisor_version	supervisor-2024.03.1
agent_version	1.6.0
docker_version	24.0.7
disk_total	30.8 GB
disk_used	10.0 GB
healthy	true
supported	true
board	ova
supervisor_api	ok
version_api	ok
installed_addons	Mosquitto broker (6.4.0), Z-Wave JS (0.4.5), Z-Wave JS UI (3.4.0), Studio Code Server (5.15.0), Advanced SSH & Web Terminal (17.2.0), Matter Server (5.4.1), Duck DNS (1.16.0), File editor (5.8.0), ESPHome (2024.3.1), Zigbee2MQTT (1.36.1-1), Log Viewer (0.17.0)

Dashboards

dashboards	2
resources	0
views	11
mode	storage

Recorder

oldest_recorder_run	March 25, 2024 at 06:02
current_recorder_run	April 4, 2024 at 09:53
estimated_db_size	94.35 MiB
database_engine	sqlite
database_version	3.44.2

Checklist

• I have enabled debug logging for my installation.
• I have filled out the issue template to the best of my ability.
• This issue only contains 1 issue (if you have multiple issues, open one issue for each issue).
• This issue is not a duplicate issue of any previous issues..

Describe the issue

The installation process of this integration was fine.
But after a few mins I've noticed some lagging of HA in general. See more detail in the Debug logs section.
My MUST inverter has this name: Must 3000W 24V 60A (PV18-3024VPM)

Reproduction steps

1. Common installation process integration
2. Add all needed credentials (in this case it is USB or serial, another fields are default value)
3. Enable this integration

Debug logs

return await component.async_unload_entry(entry)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 202, in async_unload_entry
    raise ValueError("Config entry was never loaded!")
ValueError: aded!

2024-04-04 23:06:35.747 ERROR (MainThread) [homeassistant.config_entries] Error unloading entry Must Inverter for sensor
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 724, in async_unload
    result = await component.async_unload_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/sensor/__init__.py", line 145, in async_unload_entry
    return await component.async_unload_entry(entry)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 202, in async_unload_entry
    raise ValueError("Config entry was never loaded!")
ValueError: Config entry was never loaded!
2024-04-04 23:06:35.769 ERROR (MainThread) [homeassistant.config_entries] Error unloading entry Must Inverter for binary_sensor
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 724, in async_unload
    result = await component.async_unload_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/binary_sensor/__init__.py", line 245, in async_unload_entry
    return await component.async_unload_entry(entry)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 202, in async_unload_entry
    raise ValueError("Config entry was never loaded!")
ValueError: Config entry was never loaded!
2024-04-04 23:06:35.791 ERROR (MainThread) [homeassistant.config_entries] Error unloading entry Must Inverter for number
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 724, in async_unload
    result = await component.async_unload_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/number/__init__.py", line 126, in async_unload_entry
    return await component.async_unload_entry(entry)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 202, in async_unload_entry
    raise ValueError("Config entry was never loaded!")
ValueError: Config entry was never loaded!
2024-04-04 23:06:35.850 ERROR (MainThread) [homeassistant.config_entries] Error unloading entry Must Inverter for select
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 724, in async_unload
    result = await component.async_unload_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/select/__init__.py", line 116, in async_unload_entry
    return await component.async_unload_entry(entry)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 202, in async_unload_entry
    raise ValueError("Config entry was never loaded!")
ValueError: Config entry was never loaded!
2024-04-04 23:06:35.882 ERROR (MainThread) [homeassistant.config_entries] Error unloading entry Must Inverter for switch
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 724, in async_unload
    result = await component.async_unload_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/switch/__init__.py", line 106, in async_unload_entry
    return await component.async_unload_entry(entry)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 202, in async_unload_entry
    raise ValueError("Config entry was never loaded!")
ValueError: Config entry was never loaded!
2024-04-04 23:06:35.960 ERROR (MainThread) [homeassistant.config_entries] Error unloading entry Must Inverter for button
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 724, in async_unload
    result = await component.async_unload_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/button/__init__.py", line 79, in async_unload_entry
    return await component.async_unload_entry(entry)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 202, in async_unload_entry
    raise ValueError("Config entry was never loaded!")
ValueError: Config entry was never loaded!

Diagnostics dump

No response

[mukaschultze]

@slivorezka are there any error logs before that? The error you pasted is an internal error from homeassistant and not from the integration.

Also, what string did you use for the USB device path? Did you mount this device in your docker container?

[slivorezka]

@mukaschultze

• Q: are there any error logs before that?
• A: I've a few wartings like this: WARNING (MainThread) [homeassistant.components.sensor] DEVICE_CLASS_TEMPERATURE was used from tech, this is a deprecated constant which will be removed in HA Core 2025.1. and this is it.
• Q: what string did you use for the USB device path?
• A: I've found the USB connection like the MUST inverter like this: /dev/serial/by-id/usb-1a86_USB_Serial-if00-port0
• Q:Did you mount this device in your docker container?
• A: Yes it is. I have Synology NAS and there is a docker container inside virtual machin

Also, I've installed the Must Inverter integration manually and looks like it works fine for the time being
But the first installation has been done by HACS https://my.home-assistant.io/redirect/hacs_repository/?owner=mukaschultze&repository=ha-must-inverter&category=integration

Thanks!

[slivorezka]

A little bit more info about this bug and how to fix it. There is an issue https://community.home-assistant.io/t/error-doing-job/290384
And log story short: somehow i have a lot error notification like this in log:

(MainThread) [homeassistant.config_entries] Error unloading entry Must Inverter for sensor
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 724, in async_unload...

And after some time I have very slow HA instance. Reload can fix it but later (few hrs) this issue will come back.
Also, this issue doesn't affect the Must Inverter integration functionality (I think so).
Well, there is a solution: we can disable adding logs of this integration. See here how to mahage logger https://www.home-assistant.io/integrations/logger

My configuration.yaml looks like this:

# Log level.
logger:
  default: info
  logs:
    # MUST Inverter.
    custom_components.must_inverter: critical

[devastatoralexey]

I join the problem. I have a similar behavior, after starting the integration everything works well for a while, from 5 minutes to an hour, after which the readings stop changing, and the ON itself starts to slow down very much, only a complete reboot of the ON helps, restarting the integration does not help. (or rather it helps, but not always). Below is part of the log with errors.
(my inverter: Must PH18-5248 PRO 5200W 48V)

2024-05-02 09:39:39.553 INFO (MainThread) [homeassistant.setup] Setting up must_inverter
2024-05-02 09:39:39.553 INFO (MainThread) [homeassistant.setup] Setup of domain must_inverter took 0.00 seconds
2024-05-02 09:39:39.606 INFO (MainThread) [custom_components.must_inverter] successfully connected to /dev/ttyUSB0:0

2024-05-02 09:41:55.994 WARNING (MainThread) [custom_components.must_inverter] wrong number of registers read at address 10101, expected 24, got 12

2024-05-02 09:42:06.234 WARNING (MainThread) [custom_components.must_inverter] wrong number of registers read at address 20000, expected 17, got 21
2024-05-02 09:42:08.414 WARNING (MainThread) [custom_components.must_inverter] wrong number of registers read at address 20101, expected 114, got 17

2024-05-02 09:46:56.001 WARNING (MainThread) [custom_components.must_inverter] wrong number of registers read at address 10101, expected 24, got 12

2024-05-02 09:47:06.267 WARNING (MainThread) [custom_components.must_inverter] wrong number of registers read at address 20000, expected 17, got 21

2024-05-02 10:04:04.051 ERROR (MainThread) [custom_components.must_inverter] error reading modbus data at address 15201
Traceback (most recent call last):
File "/config/custom_components/must_inverter/init.py", line 239, in read_modbus_data
response = await self._client.read_holding_registers(address=start, count=count, slave=0x04)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 175, in async_execute
raise ModbusIOException(
pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] ERROR: No response received after 3 retries
2024-05-02 10:04:04.063 INFO (MainThread) [custom_components.must_inverter] modbus client is not connected, trying to reconnect
2024-05-02 10:04:04.072 INFO (MainThread) [custom_components.must_inverter] successfully connected to /dev/ttyUSB0:0
2024-05-02 10:04:06.197 WARNING (MainThread) [custom_components.must_inverter] wrong number of registers read at address 20000, expected 17, got 21

2024-05-02 10:04:14.205 ERROR (MainThread) [custom_components.must_inverter] error reading modbus data at address 20101
Traceback (most recent call last):
File "/config/custom_components/must_inverter/init.py", line 239, in read_modbus_data
response = await self._client.read_holding_registers(address=start, count=count, slave=0x04)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 175, in async_execute
raise ModbusIOException(
pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] ERROR: No response received after 3 retries
2024-05-02 10:04:14.212 INFO (MainThread) [custom_components.must_inverter] modbus client is not connected, trying to reconnect
2024-05-02 10:04:14.217 INFO (MainThread) [custom_components.must_inverter] successfully connected to /dev/ttyUSB0:0

[mukaschultze]

@devastatoralexey I added a new config to allow changing the scan interval in the latest version. Can you change it to something like 30 seconds and see if the error stops or takes longer to happen? This integration is my first experience with modbus, I'm not familiar with what could cause that.

[devastatoralexey]

@devastatoralexey I added a new config to allow changing the scan interval in the latest version. Can you change it to something like 30 seconds and see if the error stops or takes longer to happen? This integration is my first experience with modbus, I'm not familiar with what could cause that.

I tried the new version. I changed the parameters many times, both up and down. When the interval increases, it works a little longer, but still freezes and stops taking readings. After which the entire smart home server begins to slow down. Only rebooting the integration or server helps. I can’t connect to the proprietary Wifi USB plug at all. Not on any port. I scanned all its open ports, but none of them connect. There is another software "https://solar-assistant.io/shop/products/software" I tried it, everything works with it, there are no freezes, which means the problem is still with the integration. I will continue experimenting with the parameters. Thank you for your work.

Perhaps the work of this person will help you:
https://github.com/desertkun/home-inverter-grafana-monitor/blob/master/monitor/ups/must_ph18_5248.py

add: (20-05-2024)
all problems and freezes begin after this error:

Регистратор: custom_components.must_inverter
Источник: custom_components/must_inverter/init.py:239
интеграция: Must Inverter (документация, проблемы)
Первое сообщение: 16:35:09 (1048 сообщений)
Последнее сообщение: 21:53:57

error reading modbus data at address 20000
error reading modbus data at address 10101
error reading modbus data at address 15201
error reading modbus data at address 20101
error reading modbus data at address 25201
Traceback (most recent call last):
File "/config/custom_components/must_inverter/init.py", line 239, in read_modbus_data
response = await self._client.read_holding_registers(address=start, count=count, slave=0x04)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 175, in async_execute
raise ModbusIOException(
pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] ERROR: No response received after 3 retries

[klbsss]

I have a similar behavior. All freezing. scan interval 30s not help. And cpu host machine 100%