search

MiguelAngelLV / balance_neto

Componente para Home Assistant que calcula el Balance Neto Horario para instalaciones fotovoltáicas.
37 stars 6 forks source link

Crushing HA #18

Closed andrzejzukowski closed 5 months ago

andrzejzukowski commented 5 months ago

After instalation of this add-on my HA started crushing sometimes. I wonder if it may be related anyhow to this add-on.

This error originated from a custom integration.

Logger: custom_components.balance_neto.sensor
Source: custom_components/balance_neto/sensor.py:218
integration: Balance Neto (documentation, issues)
First occurred: 08:07:29 (2 occurrences)
Last logged: 08:07:29

could not convert string to float: 'unavailable
This error originated from a custom integration.

Logger: custom_components.balance_neto.sensor
Source: custom_components/balance_neto/sensor.py:219
integration: Balance Neto (documentation, issues)
First occurred: 08:07:29 (2 occurrences)
Last logged: 08:07:29

Errors values, Import unavailable and Export unavailable

I'm not sure whether this is related to that crushes, but I can't see anything more in logs related to this problem.

MiguelAngelLV commented 5 months ago

The problem is you meter sensors is reporting invalid values, so, the balance meter can't update it

andrzejzukowski commented 5 months ago

In general add-on shows correct values, in debug mode also it reports right calculations. Maybe this is related only to first seconds after restarting HA when the sensor isn't initialized.

I'll investigate it today. May we keep this issue opened for a while?

MiguelAngelLV commented 5 months ago

Yes, not problem.

Maybe I should add a check to ignore invalid values.

andrzejzukowski commented 5 months ago

I have found some time to do researches and I found those: https://community.home-assistant.io/t/home-assistant-crashing-on-2024-4-x/715823/6 https://community.home-assistant.io/t/2024-4-3-upgrade-constantly-crashing/717553

I upgraded to 2024.4.X about 14th of April, there were no issues. After instalation of this plugin (20th April) those kind of errors started to appear constantly and then they block HA UI. I cut out some parts of the log, there were too many information about my infrastructure ;)

After disabling this plugin crushes stoped.

I would like to try to debug it (or provide more logs), but I don't know how.

2024-04-24 14:29:56.200 INFO (MainThread) [satel_integra.satel_integra] Calling handler for id: 0x00
2024-04-24 14:29:57.440 INFO (MainThread) [satel_integra.satel_integra] Calling handler for id: 0x00
2024-04-24 14:29:59.420 INFO (MainThread) [satel_integra.satel_integra] Calling handler for id: 0x00
2024-04-24 14:30:00.360 INFO (MainThread) [satel_integra.satel_integra] Calling handler for id: 0x00
2024-04-24 14:30:02.460 INFO (MainThread) [satel_integra.satel_integra] Calling handler for id: 0x00
2024-04-24 14:30:02.738 DEBUG (SyncWorker_63) [custom_components.balance_neto.sensor] Import (sensor.zamel_mew_01_0_electricity_meter_total_forward_active_energy_balanced): 30.22878
2024-04-24 14:30:02.739 DEBUG (SyncWorker_63) [custom_components.balance_neto.sensor] Export (sensor.zamel_mew_01_0_electricity_meter_total_reverse_active_energy_balanced): 30.5293
2024-04-24 14:30:02.739 DEBUG (SyncWorker_63) [custom_components.balance_neto.sensor] Updating Balance Neto. Actual Import 30.228780, Export 30.529300. Import offset 29.952180, Export offset 30.464740
2024-04-24 14:30:02.739 DEBUG (SyncWorker_63) [custom_components.balance_neto.sensor] Actual Balance -0.212040
2024-04-24 14:30:02.997 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback Task.task_wakeup(<Future cancelled>)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task cancelling name='Task-40571' coro=<RemoteProtocol._async_idle_disconnect() running at /usr/local/lib/python3.12/site-packages/androidtvremote2/remote.py:203> wait_for=<Future cancelled>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Map Extractor camera'}, 'last_changed': '2024-04-24T06:16:56.493416+00:00', 'last_reported': '2024-04-24T06:16:56.493450+00:00', 'last_updated': '2024-04-24T06:16:56.493416+00:00', 'context': {'id': '01HW7C01DDTVXDMMG1GXGT1H2G', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" result=None> is being executed.
2024-04-24 14:30:02.998 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74d9b12b90>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40572' coro=<RemoteProtocol._async_idle_disconnect() running at /usr/local/lib/python3.12/site-packages/androidtvremote2/remote.py:198>> while another task <Task finished 

2024-04-24 14:37:08.184 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:08.184 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:08.184 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:08.185 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:08.185 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:08.351 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74cc47ba60>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40889' coro=<BaseSelectorEventLoop._accept_connection2() running at /usr/local/lib/python3.12/asyncio/selector_events.py:213>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10,
MiguelAngelLV commented 5 months ago

In the integration seccion in HA, you can enable "debug mode" to enable more information and download it.

andrzejzukowski commented 5 months ago

I enabled it, but I don't have the option to download logs. I see DEBUG logs in the main log. But everything related to this plugin is:

2024-04-24 14:37:02.740 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Import (sensor.zamel_mew_01_0_electricity_meter_total_forward_active_energy_balanced): 30.28588
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Export (sensor.zamel_mew_01_0_electricity_meter_total_reverse_active_energy_balanced): 30.5293
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Updating Balance Neto. Actual Import 30.285880, Export 30.529300. Import offset 29.952180, Export offset 30.464740
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Actual Balance -0.269140

and this is surrounded by tons of errors like:

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40877' coro=<BaseSelectorEventLoop._accept_connection2() running at /usr/local/lib/python3.12/asyncio/selector_events.py:213>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Map Extractor camera'}, 'last_changed': '2024-04-24T06:16:56.493416+00:00', 'last_reported': '2024-04-24T06:16:56.493450+00:00', 'last_updated': '2024-04-24T06:16:56.493416+00:00', 'context': {'id': '01HW7C01DDTVXDMMG1GXGT1H2G', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" result=None> is being executed.
2024-04-24 14:37:00.179 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:00.180 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74f9f46cb0>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40878' coro=<RemoteProtocol._async_idle_disconnect() running at /usr/local/lib/python3.12/site-packages/androidtvremote2/remote.py:198>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Map Extractor camera'}, 'last_changed': '2024-04-24T06:16:56.493416+00:00', 'last_reported': '2024-04-24T06:16:56.493450+00:00', 'last_updated': '2024-04-24T06:16:56.493416+00:00', 'context': {'id': '01HW7C01DDTVXDMMG1GXGT1H2G', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" result=None> is being executed.
2024-04-24 14:37:02.740 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Import (sensor.zamel_mew_01_0_electricity_meter_total_forward_active_energy_balanced): 30.28588
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Export (sensor.zamel_mew_01_0_electricity_meter_total_reverse_active_energy_balanced): 30.5293
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Updating Balance Neto. Actual Import 30.285880, Export 30.529300. Import offset 29.952180, Export offset 30.464740
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Actual Balance -0.269140
2024-04-24 14:37:02.757 ERROR (SyncWorker_42) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:02.758 ERROR (SyncWorker_42) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:02.758 ERROR (SyncWorker_42) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:02.758 ERROR (SyncWorker_42) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:02.765 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74d1a8f4c0>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40879' coro=<BaseSelectorEventLoop._accept_connection2() running at /usr/local/lib/python3.12/asyncio/selector_events.py:213>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Map Extractor camera'}, 'last_changed': '2024-04-24T06:16:56.493416+00:00', 'last_reported': '2024-04-24T06:16:56.493450+00:00', 'last_updated': '2024-04-24T06:16:56.493416+00:00', 'context': {'id': '01HW7C01DDTVXDMMG1GXGT1H2G', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" result=None> is being executed.
2024-04-24 14:37:02.765 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74cc50a9b0>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40880' coro=<BaseSelectorEventLoop._accept_connection2() running at /usr/local/lib/python3.12/asyncio/selector_events.py:213>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Map Extractor camera'}, 'last_changed': '2024-04-24T06:16:56.493416+00:00', 'last_reported': '2024-04-24T06:16:56.493450+00:00', 'last_updated': '2024-04-24T06:16:56.493416+00:00', 'context': {'id': '01HW7C01DDTVXDMMG1GXGT1H2G', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" result=None> is being executed.
2024-04-24 14:37:03.628 ERROR (Recorder) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:03.629 ERROR (Recorder) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:03.753 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74dae251e0>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40881' coro=<BaseSelectorEventLoop._accept_connection2() running at /usr/local/lib/python3.12/asyncio/selector_events.py:213>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Map Extractor camera'}, 'last_changed': '2024-04-24T06:16:56.493416+00:00', 'last_reported': '2024-04-24T06:16:56.493450+00:00', 'last_updated': '2024-04-24T06:16:56.493416+00:00', 'context': {'id': '01HW7C01DDTVXDMMG1GXGT1H2G', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" result=None> is being executed.
2024-04-24 14:37:04.394 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74d31bd660>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40882' coro=<BaseSelectorEventLoop._accept_connection2() running at /usr/local/lib/python3.12/asyncio/selector_events.py:213>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Map Extractor camera'}, 'last_changed': '2024-04-24T06:16:56.493416+00:00', 'last_reported': '2024-04-24T06:16:56.493450+00:00', 'last_updated': '2024-04-24T06:16:56.493416+00:00', 'context': {'id': '01HW7C01DDTVXDMMG1GXGT1H2G', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" result=None> is being executed.
2024-04-24 14:37:04.802 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74d457ead0>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
RuntimeError: Cannot enter into task <Task pending name='Task-40883' coro=<BaseSelectorEventLoop._accept_connection2() running at /usr/local/lib/python3.12/asyncio/selector_events.py:213>> while another task <Task finished name="event trigger {'domain': 'automation', 'name': 'Update Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1690616007913', 'last_triggered': datetime.datetime(2024, 4, 24, 1, 38, 2, 88688, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Map Extractor camera'}, 'last_changed': '2024-04-24T06:16:56.493416+00:00', 'last_reported': '2024-04-24T06:16:56.493450+00:00', 'last_updated': '2024-04-24T06:16:56.493416+00:00', 'context': {'id': '01HW7C01DDTVXDMMG1GXGT1H2G', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" result=None> is being executed.
2024-04-24 14:37:04.803 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7f74d123ae00>()
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
andrzejzukowski commented 5 months ago

Maybe it's this:

2024-04-24 14:37:02.740 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Import (sensor.zamel_mew_01_0_electricity_meter_total_forward_active_energy_balanced): 30.28588
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Export (sensor.zamel_mew_01_0_electricity_meter_total_reverse_active_energy_balanced): 30.5293
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Updating Balance Neto. Actual Import 30.285880, Export 30.529300. Import offset 29.952180, Export offset 30.464740
2024-04-24 14:37:02.741 DEBUG (SyncWorker_42) [custom_components.balance_neto.sensor] Actual Balance -0.269140
2024-04-24 14:37:02.757 ERROR (SyncWorker_42) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:02.758 ERROR (SyncWorker_42) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:02.758 ERROR (SyncWorker_42) [homeassistant] Error doing job: Task was destroyed but it is pending!
2024-04-24 14:37:02.758 ERROR (SyncWorker_42) [homeassistant] Error doing job: Task was destroyed but it is pending!
andrzejzukowski commented 5 months ago

image There is no option to download more detailed logs. Of course in log file there are logs, but no more than I attached previously.

MiguelAngelLV commented 5 months ago

After disable the logging it should must offer download it

andrzejzukowski commented 5 months ago

I tried many other ways to get it work and it turned out that the problem appears only when 2 plugins are enabled in the same time:

After disabling any of those plugins HA stops crushing. Probably there is kind of deadlock.