mukaschultze / ha-must-inverter

Must Inverter plugin for HomeAssistant
MIT License
12 stars 2 forks source link

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

Open slivorezka opened 3 months ago

slivorezka commented 3 months ago

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

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 commented 3 months ago

@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 commented 3 months ago

@mukaschultze

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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

@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 commented 1 month ago

@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 commented 1 month ago

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