search

mrk-its / homeassistant-blitzortung

Custom Component for fetching lightning data from blitzortung.org
MIT License
208 stars 41 forks source link

Log flooding #87

Closed jhemak closed 5 months ago

jhemak commented 6 months ago

Whenever the sensor is updating due to detected lightning, I am getting a flood of messages in the logs to the point that I am not even sure what to copy/paste here. The sensor does update state and nothing appears broken aside from the hundreds of python-related log messages. If I disable this integration, the problem stops - so it definitely seems to be an issue with this custom code.

A few example lines:

Anyone else experiencing this with 2024.3?

jhemak commented 6 months ago

Am I the only one seeing this behavior?

BJReplay commented 6 months ago

No, I'm seeing a similar thing. I just installed this today into

Core 2024.3.3 Frontend 20240307.0

I temporarily set up the service with a wide radius (500km) near a storm off Japan as I wanted to test it, but even there, no lightning entities are being created, even though events are being captured:

image

2024-03-31 22:42:49.665 DEBUG (MainThread) [custom_components.blitzortung.mqtt] Received message on blitzortung/1.1/w/u/z/z/h/5/z/e/9/k/v/g: b'{"time": 1711885366426557400, "lat": 27.970445, "lon": 134.83458, "alt": 0, "pol": 0, "mds": 5215, "mcg": 247, "status": 0, "region": 7, "delay": 3.1, "lonc": 0, "latc": 0, "sig_num": 27}'
2024-03-31 22:42:49.666 DEBUG (SyncWorker_25) [custom_components.blitzortung] ligntning data: {'time': 1711885366426557400, 'lat': 27.970445, 'lon': 134.83458, 'alt': 0, 'pol': 0, 'mds': 5215, 'mcg': 247, 'status': 0, 'region': 7, 'delay': 3.1, 'lonc': 0, 'latc': 0, 'sig_num': 27, 'distance': 1395.0, 'azimuth': 110}
2024-03-31 22:42:49.666 DEBUG (SyncWorker_25) [custom_components.blitzortung.geo_location] geo_location lightning: {'time': 1711885366426557400, 'lat': 27.970445, 'lon': 134.83458, 'alt': 0, 'pol': 0, 'mds': 5215, 'mcg': 247, 'status': 0, 'region': 7, 'delay': 3.1, 'lonc': 0, 'latc': 0, 'sig_num': 27, 'distance': 1395.0, 'azimuth': 110}
2024-03-31 22:42:49.666 DEBUG (SyncWorker_25) [custom_components.blitzortung.geo_location] tracked lightnings: 91
2024-03-31 22:42:50.859 DEBUG (MainThread) [custom_components.blitzortung.mqtt] Received message on blitzortung/1.1/w/u/z/x/m/h/2/5/7/b/7/k: b'{"time": 1711885366463426000, "lat": 28.01707, "lon": 134.516767, "alt": 0, "pol": 0, "mds": 9609, "mcg": 245, "status": 0, "region": 7, "delay": 4.3, "lonc": 0, "latc": 0, "sig_num": 27}'
2024-03-31 22:42:50.861 DEBUG (SyncWorker_15) [custom_components.blitzortung] ligntning data: {'time': 1711885366463426000, 'lat': 28.01707, 'lon': 134.516767, 'alt': 0, 'pol': 0, 'mds': 9609, 'mcg': 245, 'status': 0, 'region': 7, 'delay': 4.3, 'lonc': 0, 'latc': 0, 'sig_num': 27, 'distance': 1365.2, 'azimuth': 111}
2024-03-31 22:42:50.861 DEBUG (SyncWorker_15) [custom_components.blitzortung.geo_location] geo_location lightning: {'time': 1711885366463426000, 'lat': 28.01707, 'lon': 134.516767, 'alt': 0, 'pol': 0, 'mds': 9609, 'mcg': 245, 'status': 0, 'region': 7, 'delay': 4.3, 'lonc': 0, 'latc': 0, 'sig_num': 27, 'distance': 1365.2, 'azimuth': 111}
2024-03-31 22:42:50.861 DEBUG (SyncWorker_15) [custom_components.blitzortung.geo_location] tracked lightnings: 92
2024-03-31 22:42:54.146 DEBUG (MainThread) [custom_components.blitzortung.mqtt] Received message on blitzortung/1.1/x/h/b/q/h/0/f/m/p/n/9/6: b'{"time": 1711885371678857000, "lat": 27.778451, "lon": 135.530736, "alt": 0, "pol": 0, "mds": 9933, "mcg": 183, "status": 0, "region": 4, "delay": 2.3, "lonc": 0, "latc": 0, "sig_num": 40}'
2024-03-31 22:42:54.147 DEBUG (SyncWorker_7) [custom_components.blitzortung] ligntning data: {'time': 1711885371678857000, 'lat': 27.778451, 'lon': 135.530736, 'alt': 0, 'pol': 0, 'mds': 9933, 'mcg': 183, 'status': 0, 'region': 4, 'delay': 2.3, 'lonc': 0, 'latc': 0, 'sig_num': 40, 'distance': 1463.8, 'azimuth': 110}
2024-03-31 22:42:54.147 DEBUG (SyncWorker_7) [custom_components.blitzortung.geo_location] geo_location lightning: {'time': 1711885371678857000, 'lat': 27.778451, 'lon': 135.530736, 'alt': 0, 'pol': 0, 'mds': 9933, 'mcg': 183, 'status': 0, 'region': 4, 'delay': 2.3, 'lonc': 0, 'latc': 0, 'sig_num': 40, 'distance': 1463.8, 'azimuth': 110}
2024-03-31 22:42:54.147 DEBUG (SyncWorker_7) [custom_components.blitzortung.geo_location] tracked lightnings: 93
2024-03-31 22:42:54.457 DEBUG (MainThread) [custom_components.blitzortung.mqtt] Received message on blitzortung/1.1/x/h/b/q/h/7/8/w/b/3/3/n: b'{"time": 1711885371678852600, "lat": 27.79383, "lon": 135.539029, "alt": 0, "pol": 0, "mds": 5193, "mcg": 226, "status": 0, "region": 7, "delay": 2.5, "lonc": 0, "latc": 0, "sig_num": 39}'
2024-03-31 22:42:54.460 DEBUG (SyncWorker_2) [custom_components.blitzortung] ligntning data: {'time': 1711885371678852600, 'lat': 27.79383, 'lon': 135.539029, 'alt': 0, 'pol': 0, 'mds': 5193, 'mcg': 226, 'status': 0, 'region': 7, 'delay': 2.5, 'lonc': 0, 'latc': 0, 'sig_num': 39, 'distance': 1463.9, 'azimuth': 110}
2024-03-31 22:42:54.460 DEBUG (SyncWorker_2) [custom_components.blitzortung.geo_location] geo_location lightning: {'time': 1711885371678852600, 'lat': 27.79383, 'lon': 135.539029, 'alt': 0, 'pol': 0, 'mds': 5193, 'mcg': 226, 'status': 0, 'region': 7, 'delay': 2.5, 'lonc': 0, 'latc': 0, 'sig_num': 39, 'distance': 1463.9, 'azimuth': 110}
2024-03-31 22:42:54.461 DEBUG (SyncWorker_2) [custom_components.blitzortung.geo_location] tracked lightnings: 94
2024-03-31 22:42:54.709 DEBUG (MainThread) [custom_components.blitzortung.mqtt] Received message on blitzortung/1.1/x/h/b/q/5/c/x/r/5/5/g/q: b'{"time": 1711885371678858500, "lat": 27.7829, "lon": 135.526447, "alt": 0, "pol": 0, "mds": 9774, "mcg": 183, "status": 0, "region": 2, "delay": 2.9, "lonc": 0, "latc": 0, "sig_num": 25}'
2024-03-31 22:42:54.712 DEBUG (SyncWorker_3) [custom_components.blitzortung] ligntning data: {'time': 1711885371678858500, 'lat': 27.7829, 'lon': 135.526447, 'alt': 0, 'pol': 0, 'mds': 9774, 'mcg': 183, 'status': 0, 'region': 2, 'delay': 2.9, 'lonc': 0, 'latc': 0, 'sig_num': 25, 'distance': 1463.2, 'azimuth': 110}
2024-03-31 22:42:54.712 DEBUG (SyncWorker_3) [custom_components.blitzortung.geo_location] geo_location lightning: {'time': 1711885371678858500, 'lat': 27.7829, 'lon': 135.526447, 'alt': 0, 'pol': 0, 'mds': 9774, 'mcg': 183, 'status': 0, 'region': 2, 'delay': 2.9, 'lonc': 0, 'latc': 0, 'sig_num': 25, 'distance': 1463.2, 'azimuth': 110}
2024-03-31 22:42:54.713 DEBUG (SyncWorker_3) [custom_components.blitzortung.geo_location] tracked lightnings: 95
2024-03-31 22:42:54.718 ERROR (Recorder) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 625, in async_add_entities
    await add_func(coros, entities, timeout)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 573, in _async_add_entities
    async with self.hass.timeout.async_timeout(timeout, self.domain):
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/util/timeout.py", line 469, in async_timeout
    current_task: asyncio.Task[Any] | None = asyncio.current_task()
                                             ^^^^^^^^^^^^^^^^^^^^^^
RuntimeError: no running event loop
2024-03-31 22:42:54.723 WARNING (Recorder) [py.warnings] /usr/local/lib/python3.12/site-packages/sqlalchemy/sql/compiler.py:1896: RuntimeWarning: coroutine 'EntityPlatform._async_add_entity' was never awaited
  bind: extracted

2024-03-31 22:42:54.723 ERROR (Recorder) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 625, in async_add_entities
    await add_func(coros, entities, timeout)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 573, in _async_add_entities
    async with self.hass.timeout.async_timeout(timeout, self.domain):
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/util/timeout.py", line 469, in async_timeout
    current_task: asyncio.Task[Any] | None = asyncio.current_task()
                                             ^^^^^^^^^^^^^^^^^^^^^^
RuntimeError: no running event loop
2024-03-31 22:42:54.728 ERROR (Recorder) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 625, in async_add_entities
    await add_func(coros, entities, timeout)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 573, in _async_add_entities
    async with self.hass.timeout.async_timeout(timeout, self.domain):
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/util/timeout.py", line 469, in async_timeout
    current_task: asyncio.Task[Any] | None = asyncio.current_task()
                                             ^^^^^^^^^^^^^^^^^^^^^^
RuntimeError: no running event loop
2024-03-31 22:42:54.732 ERROR (Recorder) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 625, in async_add_entities
    await add_func(coros, entities, timeout)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 573, in _async_add_entities
    async with self.hass.timeout.async_timeout(timeout, self.domain):
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/util/timeout.py", line 469, in async_timeout
    current_task: asyncio.Task[Any] | None = asyncio.current_task()
                                             ^^^^^^^^^^^^^^^^^^^^^^
RuntimeError: no running event loop
2024-03-31 22:42:54.734 ERROR (Recorder) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 625, in async_add_entities
    await add_func(coros, entities, timeout)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 573, in _async_add_entities
    async with self.hass.timeout.async_timeout(timeout, self.domain):
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/util/timeout.py", line 469, in async_timeout
    current_task: asyncio.Task[Any] | None = asyncio.current_task()
                                             ^^^^^^^^^^^^^^^^^^^^^^
RuntimeError: no running event loop
stalakerob commented 5 months ago

Seeing this since a lomg time. Whenever lightnings occur my log gets flooded with all kinds of errors.

jhemak commented 5 months ago

Thank you! Will watch at the next storm to confirm this is resolved.

mrk-its commented 5 months ago

Thank you! Will watch at the next storm to confirm this is resolved.

You can temporarily increase range in the configuration :]

stalakerob commented 5 months ago

I did that and the log errors are gone. THANK YOU very much for fixing this ! I also realized that the lightnings are now back on the map. Cool. :-)