basnijholt / adaptive-lighting

Adaptive Lighting custom component for Home Assistant
https://basnijholt.github.io/adaptive-lighting/
Apache License 2.0
1.86k stars 135 forks source link

Home Assistant Hangs with excessive memory usage when controlling Hue Bridge lights #899

Open thargy opened 9 months ago

thargy commented 9 months ago

Home Assistant Adaptive Lighting Issue Template

Bug Reports

If you need help with using or configuring Adaptive Lighting, please open a Q&A discussion thread here instead.

Before submitting a bug report, please follow these troubleshooting steps:

Please confirm that you have completed the following steps:

Required information for bug reports:

Please include the following information in your issue.

Issues missing this information may not be addressed.

  1. Debug logs captured while the issue occurred. See here for instructions on enabling debug logging:

The logs do not show anything substantial due to nothing being written because of memory pressure, instead, here is the dump from py_spy:

Python v3.11.6 (/usr/local/bin/python3.11)

Thread 66 (active+gil): "MainThread"
    connect (aiohttp/connector.py:520)
    _request (aiohttp/client.py:574)
    __aenter__ (aiohttp/client.py:1187)
    create_request (aiohue/v2/__init__.py:211)
    request (aiohue/v2/__init__.py:167)
    update (aiohue/v2/controllers/base.py:153)
    set_state (aiohue/v2/controllers/lights.py:97)
    async_request_call (homeassistant/components/hue/bridge.py:123)
    async_turn_on (homeassistant/components/hue/v2/light.py:246)
    async_handle_light_on_service (homeassistant/components/light/__init__.py:624)
    _run (asyncio/events.py:80)
    _run_once (asyncio/base_events.py:1925)
    run_forever (asyncio/base_events.py:607)
    run_until_complete (asyncio/base_events.py:640)
    run (homeassistant/runner.py:188)
    main (homeassistant/__main__.py:209)
    <module> (homeassistant/__main__.py:221)
    _run_code (<frozen runpy>:88)
    _run_module_as_main (<frozen runpy>:198)
Thread 87 (idle): "Thread-1 (_monitor)"
    dequeue (logging/handlers.py:1528)
    _monitor (logging/handlers.py:1579)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 89 (idle): "SyncWorker_0"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 91 (idle): "SyncWorker_1"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 93 (idle): "SyncWorker_2"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 94 (idle): "SyncWorker_3"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 97 (idle): "SyncWorker_4"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 98 (idle): "SyncWorker_5"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 101 (idle): "SyncWorker_6"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 102 (idle): "SyncWorker_7"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 103 (idle): "SyncWorker_8"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 104 (idle): "SyncWorker_9"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 105 (idle): "Recorder"
    fetchall_for_returning (sqlalchemy/engine/default.py:1726)
    _deliver_insertmanyvalues_batches (sqlalchemy/engine/default.py:798)
    _exec_insertmany_context (sqlalchemy/engine/base.py:2030)
    _execute_context (sqlalchemy/engine/base.py:1843)
    _execute_clauseelement (sqlalchemy/engine/base.py:1639)
    _execute_on_connection (sqlalchemy/sql/elements.py:516)
    execute (sqlalchemy/engine/base.py:1416)
    _emit_insert_statements (sqlalchemy/orm/persistence.py:1136)
    save_obj (sqlalchemy/orm/persistence.py:93)
    execute (sqlalchemy/orm/unitofwork.py:642)
    execute_aggregate (sqlalchemy/orm/unitofwork.py:567)
    execute (sqlalchemy/orm/unitofwork.py:463)
    _flush (sqlalchemy/orm/session.py:4408)
    flush (sqlalchemy/orm/session.py:4312)
    _prepare_impl (sqlalchemy/orm/session.py:1231)
    _go (sqlalchemy/orm/state_changes.py:139)
    _prepare_impl (<string>:2)
    commit (sqlalchemy/orm/session.py:1256)
    _go (sqlalchemy/orm/state_changes.py:139)
    commit (<string>:2)
    commit (sqlalchemy/orm/session.py:1969)
    _commit_event_session (homeassistant/components/recorder/core.py:1183)
    _commit_event_session_or_retry (homeassistant/components/recorder/core.py:1163)
    run (homeassistant/components/recorder/tasks.py:305)
    _process_one_task_or_recover (homeassistant/components/recorder/core.py:912)
    _guarded_process_one_task_or_recover (homeassistant/components/recorder/core.py:901)
    _run_event_loop (homeassistant/components/recorder/core.py:873)
    _run (homeassistant/components/recorder/core.py:779)
    run (homeassistant/components/recorder/core.py:699)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 115 (idle): "Thread-2 (_thread_main)"
    _loop (paho/mqtt/client.py:1150)
    loop_forever (paho/mqtt/client.py:1756)
    _thread_main (paho/mqtt/client.py:3591)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 116 (idle): "SyncWorker_10"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 117 (idle): "SyncWorker_11"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 118 (idle): "SyncWorker_12"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 119 (idle): "SyncWorker_13"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 122 (idle): "zeroconf-ServiceBrowser-_googlecast._tcp-122"
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 123 (idle): "Thread-3"
    wait (threading.py:331)
    wait (threading.py:629)
    run (pychromecast/discovery.py:304)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 124 (idle): "Thread-5"
    run_once (pychromecast/socket_client.py:579)
    run (pychromecast/socket_client.py:540)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 125 (idle): "Thread-6"
    run_once (pychromecast/socket_client.py:579)
    run (pychromecast/socket_client.py:540)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 126 (idle): "Thread-7"
    run_once (pychromecast/socket_client.py:579)
    run (pychromecast/socket_client.py:540)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 127 (idle): "Thread-8"
    run_once (pychromecast/socket_client.py:579)
    run (pychromecast/socket_client.py:540)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 128 (idle): "Thread-9"
    run_once (pychromecast/socket_client.py:579)
    run (pychromecast/socket_client.py:540)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 129 (idle): "Thread-10"
    run_once (pychromecast/socket_client.py:579)
    run (pychromecast/socket_client.py:540)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 144 (idle): "Thread-CallbackRequestDispatcher"
    wait (threading.py:327)
    get (queue.py:171)
    _get_many (pubsub_v1/subscriber/_protocol/helper_threads.py:56)
    __call__ (pubsub_v1/subscriber/_protocol/helper_threads.py:103)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 145 (idle): "Thread-ConsumeBidirectionalStream"
    wait (threading.py:331)
    _wait_once (grpc/_common.py:116)
    wait (grpc/_common.py:156)
    _next (grpc/_channel.py:958)
    __next__ (grpc/_channel.py:541)
    __next__ (api_core/grpc_helpers.py:119)
    _recv (api_core/bidi.py:566)
    _recoverable (api_core/bidi.py:512)
    recv (api_core/bidi.py:569)
    _thread_main (api_core/bidi.py:663)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 146 (idle): "Thread-LeaseMaintainer"
    wait (threading.py:331)
    wait (threading.py:629)
    maintain_leases (pubsub_v1/subscriber/_protocol/leaser.py:234)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 148 (idle): "Thread-Heartbeater"
    wait (threading.py:331)
    wait (threading.py:629)
    heartbeat (pubsub_v1/subscriber/_protocol/heartbeater.py:49)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 149 (idle): "Thread-13 (_run)"
    channel_spin (grpc/_channel.py:1656)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 152 (idle): "DbWorker_0"
    _worker (concurrent/futures/thread.py:81)
    _worker_with_shutdown_hook (homeassistant/components/recorder/executor.py:17)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 153 (idle): "DbWorker_1"
    _worker (concurrent/futures/thread.py:81)
    _worker_with_shutdown_hook (homeassistant/components/recorder/executor.py:17)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 154 (idle): "DHCPWatcher"
    select (scapy/supersocket.py:264)
    _run (scapy/sendrecv.py:1219)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)
Thread 268 (idle): "Thread-111 (_run)"
    wait (threading.py:331)
    get (queue.py:180)
    __iter__ (api_core/bidi.py:107)
    consume_request_iterator (grpc/_channel.py:274)
    run (threading.py:982)
    _bootstrap_inner (threading.py:1045)
    _bootstrap (threading.py:1002)

Also, you can access the sampling svg's from here, which are the most illuminating: Rate 100 Rate 200

  1. Your Adaptive Lighting configuration:
homeassistant:
  customize:
    package.node_anchors:
      # Default adaptive light options
      adaptive_options: &adaptive_options
        min_color_temp: 3000
        interval: 90
        sleep_transition: 5
        max_sunrise_time: "7:00:00"
        min_sunset_time: "21:00:00"
        brightness_mode: tanh
        brightness_mode_time_dark: 10800
        brightness_mode_time_light: 1
        detect_non_ha_changes: true
        adapt_only_on_bare_turn_on: true
        autoreset_control_seconds: 21600

adaptive_lighting:
  - name: "Back"
    <<: *adaptive_options
    lights:
      - light.back_lights
  - name: "Balcony"
    <<: *adaptive_options
    lights:
      - light.balcony_lights
  - name: "Bathroom"
    <<: *adaptive_options
    lights:
      - light.bathroom_lights
  - name: "Bedroom 1"
    <<: *adaptive_options
    lights:
      - light.bedroom_1_lights
  - name: "Bedroom 3"
    <<: *adaptive_options
    lights:
      - light.bedroom_3_lights
  - name: "Bedroom 4"
    <<: *adaptive_options
    lights:
      - light.bedroom_4_lights
  - name: "Bedroom 5"
    <<: *adaptive_options
    lights:
      - light.bedroom_5_lights
  - name: "Bedroom 6"
    <<: *adaptive_options
    lights:
      - light.bedroom_6_lights
  - name: "Conservatory"
    <<: *adaptive_options
    lights:
      - light.conservatory_lights
  - name: "Dining Room"
    <<: *adaptive_options
    lights:
      - light.dining_room_lights
  - name: "Dressing Room"
    <<: *adaptive_options
    lights:
      - light.dressing_room_lights
  - name: "Ensuite"
    <<: *adaptive_options
    lights:
      - light.ensuite_lights
  - name: "Front"
    <<: *adaptive_options
    lights:
      - light.front_lights
  - name: "Garage Attic"
    <<: *adaptive_options
    lights: []
  - name: "Garage Floor"
    <<: *adaptive_options
    lights: []
  - name: "Hallway Front"
    <<: *adaptive_options
    lights:
      - light.hallway_front_spots
  - name: "Hallway Rear"
    <<: *adaptive_options
    lights:
      - light.hallway_rear_spots
  - name: "Kitchen"
    <<: *adaptive_options
    lights:
      - light.kitchen_lights
  - name: "Landing"
    <<: *adaptive_options
    lights:
      - light.landing_lights
  - name: "Living Room"
    <<: *adaptive_options
    lights:
      - light.living_room_lights
  - name: "Plant Room"
    <<: *adaptive_options
    lights: []
  - name: "Porch"
    <<: *adaptive_options
    lights:
      - light.porch_lights
  - name: "Snug"
    <<: *adaptive_options
    lights: []
  - name: "Stairwell"
    <<: *adaptive_options
    lights:
      - light.stairwell_lights
  - name: "Toilet"
    <<: *adaptive_options
    lights:
      - light.toilet_lights
  - name: "Under Balcony"
    <<: *adaptive_options
    lights:
      - light.under_balcony_lights
  - name: "Utility"
    <<: *adaptive_options
    lights: []
  - name: "Woodshed"
    <<: *adaptive_options
    lights: []
  1. (If using Zigbee2MQTT), provide your configuration files (remove all personal information before posting): Can post on request, however over >150 devices and 2 separate z2m servers!

  2. Describe the bug and how to reproduce it: With thee above config, the memory usage would continue to grow until HA would hang within about 10 minutes.

The dump & SVG, show that adaptive lighting is running, and that most time is spent in the hue bridge integration trying to turn lights on.

The hue bridge currently only has a few lights, all in the "Snug" area, changing the lights of that area to [] (see config above) fixed the problem, confirming the issue was with adaptive lights spam calling hue bridge. During one crash cycle, I managed to disable the hue bridge and caught logs being spammed with failures to access hue bridge, sadly I could not capture that trace due to the issues around constant crash cycling.

  1. Steps to reproduce the behavior: Presumably set up a hue bridge and control lights with adaptive lights?

Note First raised this on the community before confirming issue was with interaction of adaptive lights and hue bridge.

thargy commented 8 months ago

My HA has been stable for over 24hrs after removing the Hue bridge lights from AL control.

TheAlphaLaw commented 7 months ago

After reading this, I now have found my memory issue. I have 64gb allocated to HA, so it takes a while between restarts to have an effect.

nickdos commented 5 months ago

I've been getting a lot of lockups (and restarts) too but I'm running HA OS. I'm using Deconz to control Zigbee lights, so a similar situation. Here is my error log, if it helps...

Logger: homeassistant
Source: /usr/src/homeassistant/homeassistant/runner.py:146
First occurred: 8:10:20 PM (9 occurrences)
Last logged: 8:58:49 PM

Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7feefea9c400>()
Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7feef01bdc90>()
Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7feefeb39660>()
Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7feeeee70340>()
Error doing job: Exception in callback <_asyncio.TaskStepMethWrapper object at 0x7feeeee71f60>()
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='listen state_changed' coro=<AdaptiveLightingManager.state_changed_event_listener() running at /config/custom_components/adaptive_lighting/switch.py:2299> cb=[set.remove()]> while another task <Task pending name="event trigger {'domain': 'automation', 'name': 'Update Vacuum Map Extractor camera', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.update_vacuum_map_extractor_camera', 'state': 'on', 'attributes': {'id': '1700269046245', 'last_triggered': datetime.datetime(2024, 4, 10, 17, 7, 50, 826984, tzinfo=datetime.timezone.utc), 'mode': 'parallel', 'current': 0, 'max': 10, 'friendly_name': 'Update Vacuum Map Extractor camera'}, 'last_changed': '2024-04-11T10:01:16.282475+00:00', 'last_reported': '2024-04-11T10:01:16.282506+00:00', 'last_updated': '2024-04-11T10:01:16.282475+00:00', 'context': {'id': '01HV69NEQT5F0Q5XTN5C6VHX96', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': 'state_changed', 'idx': '0', 'alias': None}}" coro=<AutomationEntity.async_trigger() running at /usr/src/homeassistant/homeassistant/components/automation/__init__.py:673>> is being executed.