FutureTense/keymaster

ISSUE: Stuck on Deleting or Adding

daelsc opened this issue · 149 comments

Describe the bug
When adding / removing Code3 from the Home Assistant dashboard the PIN Status is stuck on Deleting or Adding. All of the other code #'s work fine, can add and delete without issue.

Environment (please complete the following information):

HassOS
Unraid VM
Home Assistant 2022.3.5
zwave_js
Yale YRD-256

Logs
Paste your error logs here.

Screenshots

keymaster

Additional context

Otherwise works great!

I'm having the same issue. Only happens on one of my child locks and only 3 code slots. I deleted the lock and re-added it and the same thing happens on the same slots for the same lock. I'm trying to look at the logs, but I don't know where the logs are located.

OK I figured out how to "fix" it, or at least manually push the codes to the door. Once done, the slot shows it as "connected" or "deleted". Once I did this fix, I could change the code, disable or enable the code and it works as it should. It's almost like there was a some sort of communication problem with just those code slots and for some reason Keymaster couldn't get the lock to change the code. and when I manually pushed the code to the lock, it fixed the problem.

Here is what I did:

  1. Create a new script with the following code:
alias: Manual Set Lock Codes
sequence:
  - service: zwave_js.set_lock_usercode
    data:
      code_slot: 15 (what ever your slot is)
      usercode: 1234 (or whatever your code is)
    entity_id: lock.xxxxxx (entity ID of your lock)
mode: single
  1. Save the script
  2. Click "run script"

Sometimes I had to play around with it or maybe it just took a few minutes to work. The first slot worked right away and keymaster changed it to "connected"

The second slot I had to un-enable it, then run the script. At that point, keymaster showed it as "deleted" and when I enabled it, it showed "Adding" then shortly after "Connected"

The third slot took a few times of running the script and enabling / disabling the slot in keymaster.

Maybe it just takes time to cycle through the system when you run the script? I don't know, but as of now, it works as it should.

Oh and finally, it seems obviously, but if you have multiple slots that need to be done, make sure you change them in the script after the previous slot is fixed and save the script before running it.

Hope that all makes sense. Good luck. Any questions, please ask.

@dcf1999 That WORKED! I had a similar experience as you, had to do it a few times but eventually, it got back to a working state. Thank you so much.

I ended up forcing the automations "synchronize _______" and that fixed it for me.

I just acquired a lock from someone that had been doing manual code management on the lock itself. I ran into this same problem. My solution was to disable the offending slot and then use the developer tools / services to do the following:

call keymaster.clear_code with the lock entity_id and the code_slot defined. Once this was done, I could enter my target code and set to enable and it picked up properly from then on.

Keymaster definitely has a bit of an issue when taking over a lock that has been in use in some way outside of Keymaster management.

Keymaster definitely has a bit of an issue when taking over a lock that has been in use in some way outside of Keymaster management.

Which is funny because it's just the zwave commands wrapped up.

I just acquired a lock from someone that had been doing manual code management on the lock itself.

I've noticed this mostly happening on specific brands of lock, Yale and Schlage. Kwikset seems to work flawlessly out of the box. 🤷‍♂️

I just acquired a lock from someone that had been doing manual code management on the lock itself.

I've noticed this mostly happening on specific brands of lock, Yale and Schlage. Kwikset seems to work flawlessly out of the box. man_shrugging

The one I acquired was a Kwikset :-/ It's happened to me with two different previously used Kwiksets.

Strange, I've never had any issues with my Kwikset.

@firstof9 I only seem to have the issue with Kwikset locks if they've been used outside of Keymaster. Or in the case of one lock, a different installation of HA & Keymaster that I moved locations of! It's all around codes already being in the lock and Keymaster for some reason doesn't pick them up properly though I've seen it actually get the codes but it seems to get stuck in a weird state of deleting/adding them.

I am having this issue but with Every user code.

If you are still stuck...
I have the Schlage BE469ZP (Allegion) and have had this problem and have been trying to fix it using all the tips found with no progress. Finally here is what I did to fix my issue. I had been using the red enroll/un-enroll button in the back with the battery. I changed that method to:

Remove Z-Wave Device:

  1. In Home Assistant, got to Configuration -> Devices & Services and find your Z-Wave JS integration
  2. Click "Configure". In the Diagnostics box click "Remove Device"
  3. Since I have been using the (Enroll / Un-Enroll) button near the battery, I used this to remove it
  4. Home Assistant should now show the lock removed.
  5. Reboot (not just reset) Home Assistant Host.

Add lock again. This time use the code route

  1. In Home Assistant, got to Configuration -> Devices & Services and find your Z-Wave JS integration
  2. Click "Configure". click the "+ Add Device" at the bottom
  3. Go to your door and use the manufacturer recommended way to remove (enroll) your lock. For me (schlage BE469) I pushed the schlage button with the lock extended, typed in my programming code then when I saw the orange flashing light I pressed 0. then it takes about 5-10 seconds to add the lock
  4. Your door should be added

From this point I tried the method suggested here of manually clearing the code slots thanks to @tykeal.

I honestly am not so sure that the button in the back with the battery is secure. I think the way I wrote above to add the lock in Z-Wave JS made all the difference.

Hoping someone can help!

I also have the Schalge BE469ZP (Allegion) and have exluded it and removed all keymaster integrations 3 times now and set everything back up using @alsoszaa method of adding the lock back in. The lock connects just fine in home assistant, but I can not get this integration to work.

After installing the the integration in HACS and then adding the integration in HA, I get 11 entities (10 code slots and the network sensor). When I view those 11 entities though, the 10 card slots show as "unavailable" and the network entity shows just a "-" under status.

I'm guessing this is why, if I go through the rest of the set up process, I am unable to clear and reset codes, either in the UI or through the developer tools.

Please be gentle as I am new to HA, but would greatly appreciate any help that can be offered. Other Zwave devices are working just fine, when these sensors are generated through the integration, they are all showing as unavailable.

Thanks in advance!

the network entity shows just a "-"

If you go to dev tools -> settings -> info under system health, what does the keymaster info say?

Example:
image

Thanks for the response!

Mine is showing exactly what you have in your example.

Once the network status goes 'on' it should attempt to pull your codes from the lock and make the sensors available.

Try enabling debugging to see if there's any errors happening.

So I went to Dev Tools -> Services and selected the "logger.set_level" service and put "custom_components.keymaster: debug" and pressed "Call Service." The box turned green and I got no error messages on the screen. I then went to Configuration -> Settings -> Logs tab. I don't see anything related to keymaster, but maybe I'm not reading it correctly. Here's what comes up:

image

View your home-assistant.log file in the /config directory.

I'm having the same issue, I tried the dev tools clear code and I'm getting this in my logs;

2022-04-25 23:00:45 DEBUG (MainThread) [custom_components.keymaster] Clear Code service: <ServiceCall keymaster.clear_code (c:2cf6a44af212f2d59815c2859bdbafd4): code_slot=1, entity_id=lock.west>
2022-04-25 23:00:45 DEBUG (MainThread) [custom_components.keymaster.services] Attempting to call clear_usercode...
2022-04-25 23:00:45 ERROR (MainThread) [custom_components.keymaster.services] Error calling zwave_js.clear_lock_usercode service call: userIdStatus for code slot 1 not found
2022-04-25 23:00:45 ERROR (MainThread) [homeassistant.helpers.script.websocket_api_script] websocket_api script: Error executing script. Unexpected error for call_service at pos 1: userIdStatus for code slot 1 not found
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 379, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 582, in _async_call_service_step
    await service_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1634, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1671, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/config/custom_components/keymaster/__init__.py", line 245, in _clear_code
    await clear_code(hass, entity_id, code_slot)
  File "/config/custom_components/keymaster/services.py", line 192, in clear_code
    await call_service(
  File "/config/custom_components/keymaster/services.py", line 94, in call_service
    raise err
  File "/config/custom_components/keymaster/services.py", line 89, in call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1634, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1671, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 692, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 677, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 955, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 714, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/zwave_js/lock.py", line 134, in async_clear_lock_usercode
    await clear_usercode(self.info.node, code_slot)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 122, in clear_usercode
    value = get_code_slot_value(node, code_slot, LOCK_USERCODE_STATUS_PROPERTY)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 32, in get_code_slot_value
    raise NotFoundError(f"{property_name} for code slot {code_slot} not found")
zwave_js_server.exceptions.NotFoundError: userIdStatus for code slot 1 not found
2022-04-25 23:00:45 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [281473088680672] Error handling message: Unknown error (unknown_error)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response
    await func(hass, connection, msg)
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 630, in handle_execute_script
    await script_obj.async_run(msg.get("variables"), context=context)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1275, in async_run
    await asyncio.shield(run.async_run())
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 359, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 379, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 582, in _async_call_service_step
    await service_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1634, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1671, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/config/custom_components/keymaster/__init__.py", line 245, in _clear_code
    await clear_code(hass, entity_id, code_slot)
  File "/config/custom_components/keymaster/services.py", line 192, in clear_code
    await call_service(
  File "/config/custom_components/keymaster/services.py", line 94, in call_service
    raise err
  File "/config/custom_components/keymaster/services.py", line 89, in call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1634, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1671, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 692, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 677, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 955, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 714, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/zwave_js/lock.py", line 134, in async_clear_lock_usercode
    await clear_usercode(self.info.node, code_slot)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 122, in clear_usercode
    value = get_code_slot_value(node, code_slot, LOCK_USERCODE_STATUS_PROPERTY)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 32, in get_code_slot_value
    raise NotFoundError(f"{property_name} for code slot {code_slot} not found")
zwave_js_server.exceptions.NotFoundError: userIdStatus for code slot 1 not found

This means your lock didn't complete the interview.

Thanks, weird as the lock was working for months, I added another lock and it seems to be having issues. I'll try re-interviewing.
Thanks.

Still showing the code slots as unavailable.

Need those logs to help you find out why.

Good morning, sorry the delay. I've been out of town on work. Are these the logs you are hoping to see:

2022-04-24 22:06:30 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration keymaster which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-04-24 22:06:30 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-04-24 22:06:41 WARNING (MainThread) [hass_nabucasa.cloud_api] Fetched https://alexa-api.nabucasa.com/access_token (400)
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of counter is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.components.scene] Setup of scene platform homeassistant is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.components.update] Setup of update platform hassio is taking over 10 seconds.
2022-04-24 22:06:57 WARNING (MainThread) [homeassistant.components.lock] Setup of lock platform template is taking over 10 seconds.
2022-04-24 22:06:58 WARNING (MainThread) [homeassistant.setup] Setup of tplink is taking over 10 seconds.
2022-04-24 22:07:04 WARNING (MainThread) [homeassistant.components.dlna_dms] Failed connecting to recently alive device at http://192.168.1.100:2869/upnphost/udhisapi.dll?content=uuid:2c8242fa-27f3-48b4-b5f0-ef1046ea3df7: UpnpActionResponseError('Error during async_call(), status: 500, upnp error: 501 (Action Failed)')
2022-04-24 22:07:12 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x6805:1:0x0300]: async_initialize: all attempts have failed: [DeliveryError('[0x6805:1:0x0300]: Message send failure'), DeliveryError('[0x6805:1:0x0300]: Message send failure'), DeliveryError('[0x6805:1:0x0300]: Message send failure'), DeliveryError('[0x6805:1:0x0300]: Message send failure')]
2022-04-24 22:07:13 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x6805:1:0x0008]: async_initialize: all attempts have failed: [DeliveryError('[0x6805:1:0x0008]: Message send failure'), DeliveryError('[0x6805:1:0x0008]: Message send failure'), DeliveryError('[0x6805:1:0x0008]: Message send failure'), DeliveryError('[0x6805:1:0x0008]: Message send failure')]
2022-04-24 22:07:53 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x6805:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x6805:1:0x0006]: Message send failure'), DeliveryError('[0x6805:1:0x0006]: Message send failure'), DeliveryError('[0x6805:1:0x0006]: Message send failure'), DeliveryError('[0x6805:1:0x0006]: Message send failure')]
2022-04-24 22:09:03 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x81EF:1:0x0300]: async_initialize: all attempts have failed: [TimeoutError(), TimeoutError(), TimeoutError(), TimeoutError()]
2022-04-24 22:09:04 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x81EF:1:0x0008]: async_initialize: all attempts have failed: [TimeoutError(), TimeoutError(), TimeoutError(), TimeoutError()]
2022-04-24 22:09:04 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x81EF:1:0x0006]: async_initialize: all attempts have failed: [TimeoutError(), TimeoutError(), TimeoutError(), TimeoutError()]
2022-04-24 22:11:00 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x81EF:1:0x0702]: async_initialize: all attempts have failed: [TimeoutError(), TimeoutError(), TimeoutError(), TimeoutError()]
2022-04-24 22:11:08 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x06'
2022-04-24 22:33:40 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:33:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:33:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:33:45 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:33:45 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:39:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:39:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:39:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:39:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:39:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:50:28 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:50:28 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:50:28 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:50:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:50:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:53:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:53:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:53:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:53:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:53:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 22:53:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-24 23:13:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xd9'
2022-04-24 23:14:06 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe8'
2022-04-25 00:15:57 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x06'
2022-04-25 00:24:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x16'
2022-04-25 00:35:53 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x56'
2022-04-25 01:12:36 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xcb'
2022-04-25 01:18:24 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x66'
2022-04-25 01:20:12 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb1'
2022-04-25 01:31:10 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x8a'
2022-04-25 01:47:36 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x53'
2022-04-25 02:23:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xad'
2022-04-25 02:37:50 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x1f'
2022-04-25 02:59:19 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x3a'
2022-04-25 03:26:18 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xdf'
2022-04-25 03:44:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x8d'
2022-04-25 03:53:39 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb5'
2022-04-25 04:11:02 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x5a'
2022-04-25 04:18:03 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xf7'
2022-04-25 04:29:21 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x23'
2022-04-25 04:32:19 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x5e'
2022-04-25 05:13:20 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x85'
2022-04-25 05:16:09 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xbd'
2022-04-25 05:22:45 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x84'
2022-04-25 05:26:47 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xdb'
2022-04-25 05:32:24 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x69'
2022-04-25 06:04:12 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xc5'
2022-04-25 06:35:27 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe9'
2022-04-25 06:53:07 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 06:53:12 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 06:55:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 06:56:42 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 06:56:45 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 06:57:22 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:00:12 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:00:12 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:00:19 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:04:29 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:04:29 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:04:35 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:08:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:08:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:31:11 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:31:16 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:33:48 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:33:53 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 07:38:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xda'
2022-04-25 07:58:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xeb'
2022-04-25 08:11:06 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 08:11:06 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 08:11:11 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 08:13:53 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x83'
2022-04-25 08:14:31 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 08:14:31 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 08:14:37 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 08:35:33 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xdb'
2022-04-25 08:41:33 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x70'
2022-04-25 09:10:59 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 09:10:59 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 09:11:04 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 09:14:11 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 09:14:11 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 09:14:15 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 09:38:00 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x55'
2022-04-25 09:44:36 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xcd'
2022-04-25 10:01:52 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x8c'
2022-04-25 10:04:22 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: [Errno 104] Connection reset by peer
2022-04-25 10:09:37 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x71'
2022-04-25 10:10:00 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:10:14 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:10:39 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:17:03 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:17:18 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:20:40 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 503, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:20:47 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 503, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:21:11 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:21:47 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:24:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xbe'
2022-04-25 10:28:01 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:28:22 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:28:35 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 503, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:29:18 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:30:07 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:31:24 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:34:00 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:37:12 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 10:37:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 10:37:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 10:38:33 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-25 10:40:39 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 10:40:43 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 11:42:54 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x8a'
2022-04-25 11:48:59 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 11:48:59 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 11:49:17 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 11:54:48 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 11:54:53 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 12:45:21 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xf1'
2022-04-25 13:02:04 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:02:05 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:02:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:02:19 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:02:20 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:03:00 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:03:00 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:03:05 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:08:06 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:08:11 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:24:22 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:25:06 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:26:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:26:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:26:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:33:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:33:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:33:46 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:36:52 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:36:52 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:37:03 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:39:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xf9'
2022-04-25 13:44:02 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:44:02 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:44:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:44:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x6c'
2022-04-25 13:45:48 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:45:48 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:45:52 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 13:45:53 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 14:19:13 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe9'
2022-04-25 14:34:54 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x9d'
2022-04-25 14:50:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x20'
2022-04-25 14:51:10 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x46'
2022-04-25 14:56:29 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xd3'
2022-04-25 16:02:54 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x56'
2022-04-25 16:11:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x69'
2022-04-25 16:47:52 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-25 16:48:00 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xc0'
2022-04-25 16:48:23 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-25 16:57:55 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/batch/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-25 16:58:15 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/social/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-25 17:04:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x8b'
2022-04-25 17:13:53 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-25 17:14:23 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-25 17:14:53 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-25 17:15:23 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-25 17:15:53 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-25 17:18:42 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xc8'
2022-04-25 17:19:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:19:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:19:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:20:08 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:22:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:50:59 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:50:59 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:51:20 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:51:50 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:51:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:56:44 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:57:36 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x48'
2022-04-25 17:59:12 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 17:59:12 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:01:08 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:01:08 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:01:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:01:28 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:01:28 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:01:35 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:02:32 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:02:32 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:07:01 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xbd'
2022-04-25 18:12:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:12:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:17:01 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:17:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:23:39 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:23:40 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:23:50 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 18:28:34 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xc0'
2022-04-25 19:39:52 WARNING (Thread-7) [pychromecast.socket_client] [TV(192.168.1.133):8009] Heartbeat timeout, resetting connection
2022-04-25 19:40:22 ERROR (Thread-7) [pychromecast.socket_client] [TV(192.168.1.133):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.133', 8009)), retrying in 5.0s
2022-04-25 19:53:06 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/batch/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-25 20:02:52 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 20:02:52 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 20:09:16 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 20:09:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 20:12:05 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/social/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-25 21:07:32 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 21:08:06 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 21:08:06 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 21:08:45 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-25 21:44:28 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:1625b5fd-f112-41c5-85ea-cabfa7a89993, reason: UpnpConnectionTimeoutError('', None)
2022-04-25 21:44:33 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:a2682af6-d6ff-40c6-bd0c-fdc41aef1260, reason: UpnpConnectionTimeoutError('', None)
2022-04-25 21:54:49 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x34'
2022-04-25 22:58:05 ERROR (MainThread) [homeassistant.core] Error executing service: <ServiceCall switch.turn_off (c:1a41e6e3a80995e1800573307dc60893): entity_id=['switch.bonus_room_switch']>
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/core.py", line 1652, in catch_exceptions
    await coro_or_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1671, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 204, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 677, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 955, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 714, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/zwave_js/switch.py", line 83, in async_turn_off
    await self.info.node.async_set_value(self._target_value, False)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/model/node/__init__.py", line 441, in async_set_value
    result = await self.async_send_command(
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/model/node/__init__.py", line 398, in async_send_command
    result = await self.client.async_send_command(message, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/client.py", line 103, in async_send_command
    return await future
zwave_js_server.exceptions.FailedZWaveCommand: Z-Wave error 204: Failed to send the command after 3 attempts (Status NoAck) (ZW0204)
2022-04-25 23:09:51 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x76'
2022-04-25 23:14:04 ERROR (MainThread) [custom_components.hacs] HACS is disabled - HacsDisabledReason.RATE_LIMIT
2022-04-25 23:16:38 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x16'
2022-04-25 23:18:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x3b'
2022-04-25 23:24:51 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb4'
2022-04-25 23:34:08 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x61'
2022-04-26 00:24:54 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xbc'
2022-04-26 00:32:36 ERROR (MainThread) [homeassistant.components.tplink.coordinator] Error fetching 192.168.1.108 data: Unable to connect to the device: 192.168.1.108
2022-04-26 01:02:27 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xbc'
2022-04-26 02:17:34 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xc0'
2022-04-26 06:20:16 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x10'
2022-04-26 06:27:00 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x35'
2022-04-26 06:27:22 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x4e'
2022-04-26 06:28:48 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x68'
2022-04-26 06:51:32 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 06:51:37 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 06:53:22 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 06:53:39 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 06:59:29 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 06:59:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 07:01:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 07:01:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 07:59:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 07:59:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 08:16:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 08:16:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 10:10:27 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x08'
2022-04-26 10:34:06 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x51'
2022-04-26 11:15:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x9c'
2022-04-26 11:36:43 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 11:36:49 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 13:19:12 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb2'
2022-04-26 14:30:08 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 14:34:43 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 14:35:35 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 14:35:37 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 14:36:17 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 14:36:19 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 14:48:25 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/batch/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-26 15:17:58 WARNING (MainThread) [hass_nabucasa.cloud_api] Fetched https://alexa-api.nabucasa.com/access_token (400)
2022-04-26 15:17:58 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 367, in _handle_entity_registry_updated
    await self._sync_helper(to_update, to_remove)
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 311, in _sync_helper
    await self.async_get_access_token()
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 173, in async_get_access_token
    raise alexa_errors.RequireRelink
homeassistant.components.alexa.errors.RequireRelink
2022-04-26 15:19:34 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xf4'
2022-04-26 16:05:48 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 16:05:50 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 16:05:56 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 16:09:49 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 16:09:51 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 16:09:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 16:13:44 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xba'
2022-04-26 16:20:31 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 16:20:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 16:26:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xa3'
2022-04-26 17:04:53 WARNING (Thread-7) [pychromecast.socket_client] [TV(192.168.1.133):8009] Heartbeat timeout, resetting connection
2022-04-26 17:05:11 ERROR (Thread-7) [pychromecast.socket_client] [TV(192.168.1.133):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.133', 8009)), retrying in 5.0s
2022-04-26 17:07:49 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:baf11aa6-c5ac-11ec-8000-800000000000, reason: UpnpConnectionError("Cannot connect to host 192.168.1.133:52323 ssl:default [Connect call failed ('192.168.1.133', 52323)]", None)
2022-04-26 17:07:52 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:baf66e0c-c5ac-11ec-8000-800000000000, reason: UpnpConnectionError("Cannot connect to host 192.168.1.133:52323 ssl:default [Connect call failed ('192.168.1.133', 52323)]", None)
2022-04-26 17:07:55 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:bafabba6-c5ac-11ec-8000-800000000000, reason: UpnpConnectionError("Cannot connect to host 192.168.1.133:52323 ssl:default [Connect call failed ('192.168.1.133', 52323)]", None)
2022-04-26 17:16:54 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:16:56 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:29:00 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:29:02 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:33:19 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:42:17 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:42:19 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:50:50 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:50:52 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 17:51:09 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:16:28 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/batch/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-26 19:28:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:29:00 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:29:07 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:29:27 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:29:29 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:29:36 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:35:31 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:35:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:41:59 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:42:01 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:42:40 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:42:49 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 19:44:51 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xde'
2022-04-26 20:03:48 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:03:50 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:04:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:04:43 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:07:57 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:08:03 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:08:30 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:08:32 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:08:38 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:11:27 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xd7'
2022-04-26 20:25:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xca'
2022-04-26 20:34:31 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 20:34:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 21:51:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x9d'
2022-04-26 21:53:40 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x0e'
2022-04-26 22:15:20 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 22:16:05 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 22:16:05 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-26 23:21:02 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x49'
2022-04-26 23:34:24 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x8b'
2022-04-26 23:43:45 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x5a'
2022-04-27 00:21:13 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x2f'
2022-04-27 02:43:33 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x9e'
2022-04-27 03:18:48 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x4c'
2022-04-27 04:39:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x38'
2022-04-27 05:52:42 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x62'
2022-04-27 07:01:50 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:01:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:04:19 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:04:21 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:04:48 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-27 07:04:50 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:04:52 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:05:04 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-27 07:05:28 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:06:33 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-27 07:06:47 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-27 07:08:36 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-27 07:08:53 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-27 07:09:18 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-27 07:10:25 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:10:40 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:12:49 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:12:51 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:13:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:13:24 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:13:30 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:13:32 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:13:38 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:13:44 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 07:19:40 WARNING (MainThread) [hass_nabucasa.iot] Cannot connect because unable to refresh token: Too many requests
2022-04-27 07:19:44 WARNING (MainThread) [hass_nabucasa.iot] Cannot connect because unable to refresh token: Too many requests
2022-04-27 07:19:56 WARNING (MainThread) [hass_nabucasa.iot] Cannot connect because unable to refresh token: Too many requests
2022-04-27 07:20:15 WARNING (MainThread) [hass_nabucasa.iot] Cannot connect because unable to refresh token: Too many requests
2022-04-27 07:20:54 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 503, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-27 07:43:16 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xee'
2022-04-27 08:34:02 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe2'
2022-04-27 08:51:52 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb0'
2022-04-27 08:54:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x16'
2022-04-27 09:30:12 ERROR (MainThread) [homeassistant.components.speedtestdotnet] Error fetching speedtestdotnet data: Unable to connect to servers to test latency.
2022-04-27 09:46:54 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x06'
2022-04-27 10:54:21 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x70'
2022-04-27 11:06:20 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x9d'
2022-04-27 11:57:06 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xaf'
2022-04-27 13:09:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x94'
2022-04-27 13:17:23 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:17:25 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:17:36 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:20:40 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:20:42 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:20:48 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:22:12 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:22:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:22:20 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:31:10 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xee'
2022-04-27 13:38:38 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xaa'
2022-04-27 13:49:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:49:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 13:53:01 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 14:17:06 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x7f'
2022-04-27 14:23:47 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x11'
2022-04-27 14:29:24 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xa3'
2022-04-27 14:37:50 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x81'
2022-04-27 15:20:10 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x81'
2022-04-27 15:20:11 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x8a'
2022-04-27 16:10:56 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x6c'
2022-04-27 16:14:29 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xbe'
2022-04-27 16:21:51 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/social/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-27 16:48:56 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 16:48:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:10:36 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:10:38 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:14:08 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:14:10 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:14:16 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:14:23 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:16:39 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:18:29 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:18:31 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 17:26:16 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x0e'
2022-04-27 17:52:28 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x92'
2022-04-27 18:24:31 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x95'
2022-04-27 18:29:19 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x12'
2022-04-27 18:31:15 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x58'
2022-04-27 18:41:30 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/social/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-27 18:43:14 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x6b'
2022-04-27 18:53:27 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:53:29 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:54:17 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:54:31 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:54:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:55:26 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:55:28 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:55:35 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:56:31 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:56:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:56:39 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:58:02 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 18:58:13 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 20:27:10 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x8c'
2022-04-27 21:01:30 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 21:01:43 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 21:34:48 ERROR (MainThread) [homeassistant.components.xbox] Error requesting xbox data: 503, message='Service Unavailable', url=URL('https://peoplehub.xboxlive.com/users/me/people/batch/decoration/preferredcolor,detail,multiplayersummary,presencedetail')
2022-04-27 22:21:39 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x81'
2022-04-27 22:25:00 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:25:20 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:25:20 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:26:07 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:26:07 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:26:09 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:26:09 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:26:38 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:26:38 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-27 22:48:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:49:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:50:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:50:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:51:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:51:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:52:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:52:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:53:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:53:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:54:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:54:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:55:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:55:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:56:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:56:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:57:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xc0'
2022-04-27 22:57:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:57:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:58:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:58:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:59:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 22:59:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:00:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:00:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:01:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:01:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:02:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:02:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:03:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:03:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:04:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:04:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:05:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:05:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:06:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:06:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:07:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:07:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:08:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:08:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:09:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:09:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:10:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:10:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:11:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:11:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:12:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:12:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:13:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:13:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:14:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:14:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:15:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:15:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:16:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:16:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:17:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:17:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:18:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:18:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:19:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:19:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:20:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:20:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:21:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:21:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:22:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:22:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:23:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:23:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:24:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:24:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:25:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:25:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:26:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:26:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:27:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:27:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:28:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:28:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:29:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:29:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:30:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:30:56 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:31:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:31:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:32:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:32:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:33:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:33:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:34:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:34:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:35:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:35:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:36:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:36:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:37:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:37:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:38:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:38:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:39:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:39:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:40:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:40:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:41:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:41:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:42:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:42:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:43:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:43:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:44:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:44:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:45:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:45:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:46:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:46:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:47:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:47:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:48:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:48:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:49:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:49:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:50:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:50:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:51:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:51:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:52:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:52:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:53:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:53:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:54:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:54:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:55:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:55:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:56:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:56:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:57:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:57:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:58:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:58:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:59:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-27 23:59:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:00:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:00:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:01:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:01:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:02:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:02:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:03:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:03:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:04:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:04:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:05:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:05:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:06:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:06:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:07:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:07:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:08:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:08:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:09:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:09:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:10:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:10:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:11:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:11:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:12:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:12:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:13:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:13:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:14:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:14:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:15:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:15:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:16:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:16:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:17:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:17:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:18:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:18:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:19:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x0c'
2022-04-28 00:19:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:19:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:20:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:20:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:21:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:21:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:22:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:22:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:23:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:23:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:24:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:24:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:25:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:25:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:26:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:26:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:27:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:27:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:28:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:28:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:29:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:29:51 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xc9'
2022-04-28 00:29:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:30:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:30:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:31:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:31:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:32:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:32:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:33:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:33:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:34:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:34:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:35:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:35:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:36:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:36:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:37:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:37:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:38:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:38:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:39:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:39:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:40:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:40:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:41:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:41:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:42:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:42:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:43:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:43:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:44:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:44:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:45:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:45:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:46:27 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:46:57 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:47:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:47:58 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:48:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:48:58 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:49:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:49:58 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:50:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 00:50:58 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 01:11:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of binary_sensor.living_room_occupancy is taking over 10 seconds
2022-04-28 01:25:48 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xf7'
2022-04-28 01:29:22 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x3e'
2022-04-28 01:40:37 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x19'
2022-04-28 02:20:08 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe3'
2022-04-28 03:06:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xf1'
2022-04-28 04:01:40 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe0'
2022-04-28 04:11:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x76'
2022-04-28 04:26:21 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x88'
2022-04-28 04:28:40 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb4'
2022-04-28 06:57:17 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 06:57:19 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 06:57:25 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 07:00:09 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 07:00:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 07:00:55 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 07:00:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 07:05:55 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x12'
2022-04-28 07:26:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x0d'
2022-04-28 08:08:58 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x5e'
2022-04-28 08:15:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x18'
2022-04-28 08:24:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe8'
2022-04-28 08:27:05 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x34'
2022-04-28 09:12:01 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x94'
2022-04-28 10:15:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb9'
2022-04-28 10:27:27 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xd0'
2022-04-28 10:30:48 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x3b'
2022-04-28 10:35:40 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xaf'
2022-04-28 10:36:28 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xcc'
2022-04-28 10:47:48 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x06'
2022-04-28 10:55:52 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xc0'
2022-04-28 12:01:24 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 12:04:38 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 12:06:19 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 12:06:21 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 12:07:18 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 12:07:21 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 12:19:43 WARNING (Thread-7) [pychromecast.socket_client] [TV(192.168.1.133):8009] Heartbeat timeout, resetting connection
2022-04-28 12:20:13 ERROR (Thread-7) [pychromecast.socket_client] [TV(192.168.1.133):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.133', 8009)), retrying in 5.0s
2022-04-28 12:24:14 WARNING (MainThread) [hass_nabucasa.iot] Unable to connect: 504, message='Invalid response status', url=URL('wss://cloud.nabucasa.com/websocket')
2022-04-28 12:40:25 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xdb'
2022-04-28 13:16:36 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:17:06 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:17:36 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:18:06 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:23:06 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:23:36 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:24:06 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:24:36 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:25:06 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:25:36 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:26:06 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:26:36 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:27:06 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 13:56:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x08'
2022-04-28 14:10:52 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x77'
2022-04-28 14:27:37 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 14:28:11 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x26'
2022-04-28 15:01:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x31'
2022-04-28 15:01:38 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x46'
2022-04-28 15:21:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 15:21:16 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 15:23:07 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 15:23:37 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bedroom_lamp_electrical_measurement is taking over 10 seconds
2022-04-28 15:38:07 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 15:52:24 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x31'
2022-04-28 15:57:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 16:42:40 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x0a'
2022-04-28 16:43:33 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 16:44:13 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x4a'
2022-04-28 17:02:14 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 17:02:16 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 17:03:45 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 17:03:47 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 17:33:56 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x36'
2022-04-28 17:43:32 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 17:43:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 17:43:50 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 17:51:44 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 17:51:46 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 18:24:42 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x5f'
2022-04-28 19:09:28 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xa1'
2022-04-28 19:15:28 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x3c'
2022-04-28 20:00:51 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 20:01:07 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 20:37:50 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x69'
2022-04-28 21:28:52 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 21:28:55 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 21:31:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x45'
2022-04-28 21:52:39 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 21:52:41 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 21:52:47 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 21:57:03 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 21:57:05 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 21:57:11 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:02:06 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:02:08 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:02:08 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:03:36 WARNING (Thread-3) [homeassistant.components.mqtt] Disconnected from MQTT server core-mosquitto:1883 (7)
2022-04-28 22:38:32 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x20'
2022-04-28 22:38:44 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:43:23 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:43:23 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:43:25 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:43:25 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:44:47 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-28 22:49:40 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x6f'
2022-04-28 22:52:45 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe3'
2022-04-28 23:09:13 ERROR (MainThread) [homeassistant.components.tplink.coordinator] Error fetching 192.168.1.101 data: Unable to connect to the device: 192.168.1.101
2022-04-29 00:20:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x45'
2022-04-29 01:10:50 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x14'
2022-04-29 01:30:12 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x24'
2022-04-29 02:10:43 ERROR (MainThread) [homeassistant.components.tplink.coordinator] Error fetching 192.168.1.101 data: Unable to connect to the device: 192.168.1.101
2022-04-29 02:15:06 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x7e'
2022-04-29 02:26:44 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x7e'
2022-04-29 02:29:52 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xef'
2022-04-29 02:30:23 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x0f'
2022-04-29 02:52:22 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x0a'
2022-04-29 03:22:33 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xdd'
2022-04-29 03:43:08 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb9'
2022-04-29 04:30:00 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x5b'
2022-04-29 04:33:54 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xb2'
2022-04-29 05:24:40 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xa8'
2022-04-29 05:30:56 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x55'
2022-04-29 05:58:17 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xdb'
2022-04-29 06:10:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x3f'
2022-04-29 06:11:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x60'
2022-04-29 06:34:44 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xdb'
2022-04-29 06:44:54 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xe1'
2022-04-29 07:06:12 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x33'
2022-04-29 07:14:58 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:15:00 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:15:06 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:16:04 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xfc'
2022-04-29 07:20:03 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:20:05 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:23:46 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:23:48 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:23:55 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:24:20 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:24:28 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:26:32 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:26:34 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:26:40 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 07:44:30 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x25'
2022-04-29 07:52:21 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xfc'
2022-04-29 08:11:51 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 08:11:53 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 08:11:59 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 08:15:55 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 08:15:57 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 08:16:46 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 08:19:07 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0xa5'
2022-04-29 08:31:05 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running
2022-04-29 08:31:07 WARNING (MainThread) [homeassistant.components.automation.back_door_opens] Back Door Opens: Already running

These contain no debug logs from keymaster.

I double checked my configuration.yaml file to ensure that logging was enable using the instructions above. Then I called the service through Dev Tools -> Services from the instruction and got a green check mark. This is what was added to the log when I called the service:

2022-04-29 08:49:14 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:19 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:24 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:29 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:34 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:39 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:44 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:49 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:54 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:49:59 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:04 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:09 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:14 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:19 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:24 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:29 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:34 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:39 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:44 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:49 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:54 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:50:59 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:04 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:09 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:14 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:19 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:24 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:29 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:34 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:39 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:44 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:49 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:54 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:51:59 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:52:04 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:52:09 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:52:14 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 08:52:19 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)

Try making your configuration yaml similar to this:

logger:
  default: error
  logs:
     custom_components.keymaster: debug

and restart Home Assistant, this will give a better run down of what's going on.

I really appreciate your help with this Chris!

I updated the configuration.yaml file as you showed above and restarted HA. Here's what is in the log now:

2022-04-29 09:03:38 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-04-29 09:03:38 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration keymaster which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-04-29 09:04:31 INFO (MainThread) [custom_components.keymaster] Version v0.0.79 is starting, if you have any issues please report them here: https://github.com/FutureTense/keymaster
2022-04-29 09:04:32 DEBUG (MainThread) [custom_components.keymaster.binary_sensor] Connected to zwave_js network
2022-04-29 09:04:32 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:04:35 ERROR (MainThread) [zigpy.application] Couldn't start application
2022-04-29 09:04:35 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start deCONZ = dresden elektronik deCONZ protocol: ConBee I/II, RaspBee I/II coordinator
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
    fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 182, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/usr/local/lib/python3.9/site-packages/zigpy/application.py", line 69, in new
    await app.startup(auto_form)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/zigbee/application.py", line 67, in startup
    self.version = await self._api.version()
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 463, in version
    (self._proto_ver,) = await self[NetworkParameter.protocol_version]
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 428, in read_parameter
    r = await self._command(Command.read_parameter, 1 + len(data), param, data)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 313, in _command
    return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT)
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
2022-04-29 09:04:35 ERROR (MainThread) [homeassistant.components.automation.living_room_lights_remote] Unknown error while setting up trigger (empty result) Living Room Lights Remote
2022-04-29 09:04:35 ERROR (MainThread) [homeassistant.components.automation.living_room_lights_remote] Unknown error while setting up trigger (empty result) Living Room Lights Remote
2022-04-29 09:04:35 ERROR (MainThread) [homeassistant.components.automation.living_room_lights_remote] Unknown error while setting up trigger (empty result) Living Room Lights Remote
2022-04-29 09:04:35 ERROR (MainThread) [homeassistant.components.automation.living_room_lights_remote] Unknown error while setting up trigger (empty result) Living Room Lights Remote
2022-04-29 09:04:37 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:04:41 ERROR (MainThread) [zigpy.application] Couldn't start application
2022-04-29 09:04:41 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start deCONZ = dresden elektronik deCONZ protocol: ConBee I/II, RaspBee I/II coordinator
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
    fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 182, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/usr/local/lib/python3.9/site-packages/zigpy/application.py", line 69, in new
    await app.startup(auto_form)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/zigbee/application.py", line 67, in startup
    self.version = await self._api.version()
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 463, in version
    (self._proto_ver,) = await self[NetworkParameter.protocol_version]
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 428, in read_parameter
    r = await self._command(Command.read_parameter, 1 + len(data), param, data)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 313, in _command
    return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT)
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
2022-04-29 09:04:42 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:04:47 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:04:52 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:04:54 ERROR (MainThread) [zigpy.application] Couldn't start application
2022-04-29 09:04:54 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start deCONZ = dresden elektronik deCONZ protocol: ConBee I/II, RaspBee I/II coordinator
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
    fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 182, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/usr/local/lib/python3.9/site-packages/zigpy/application.py", line 69, in new
    await app.startup(auto_form)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/zigbee/application.py", line 67, in startup
    self.version = await self._api.version()
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 463, in version
    (self._proto_ver,) = await self[NetworkParameter.protocol_version]
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 428, in read_parameter
    r = await self._command(Command.read_parameter, 1 + len(data), param, data)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 313, in _command
    return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT)
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
2022-04-29 09:04:57 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:02 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:07 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:12 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:16 ERROR (MainThread) [zigpy.application] Couldn't start application
2022-04-29 09:05:16 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start deCONZ = dresden elektronik deCONZ protocol: ConBee I/II, RaspBee I/II coordinator
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
    fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 182, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/usr/local/lib/python3.9/site-packages/zigpy/application.py", line 69, in new
    await app.startup(auto_form)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/zigbee/application.py", line 67, in startup
    self.version = await self._api.version()
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 463, in version
    (self._proto_ver,) = await self[NetworkParameter.protocol_version]
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 428, in read_parameter
    r = await self._command(Command.read_parameter, 1 + len(data), param, data)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 313, in _command
    return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT)
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
2022-04-29 09:05:17 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:22 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:27 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:32 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:40 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:45 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:50 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:55 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:05:58 ERROR (MainThread) [zigpy.application] Couldn't start application
2022-04-29 09:05:58 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start deCONZ = dresden elektronik deCONZ protocol: ConBee I/II, RaspBee I/II coordinator
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
    fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 182, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/usr/local/lib/python3.9/site-packages/zigpy/application.py", line 69, in new
    await app.startup(auto_form)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/zigbee/application.py", line 67, in startup
    self.version = await self._api.version()
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 463, in version
    (self._proto_ver,) = await self[NetworkParameter.protocol_version]
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 428, in read_parameter
    r = await self._command(Command.read_parameter, 1 + len(data), param, data)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 313, in _command
    return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT)
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
2022-04-29 09:06:00 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:05 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:10 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:15 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:20 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:25 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:30 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:35 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:40 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:45 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:50 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:06:55 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:07:00 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:07:05 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:07:10 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:07:15 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:07:20 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:07:20 ERROR (MainThread) [zigpy.application] Couldn't start application
2022-04-29 09:07:20 ERROR (MainThread) [homeassistant.components.zha.core.gateway] Couldn't start deCONZ = dresden elektronik deCONZ protocol: ConBee I/II, RaspBee I/II coordinator
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
    fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/core/gateway.py", line 182, in async_initialize
    self.application_controller = await app_controller_cls.new(
  File "/usr/local/lib/python3.9/site-packages/zigpy/application.py", line 69, in new
    await app.startup(auto_form)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/zigbee/application.py", line 67, in startup
    self.version = await self._api.version()
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 463, in version
    (self._proto_ver,) = await self[NetworkParameter.protocol_version]
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 428, in read_parameter
    r = await self._command(Command.read_parameter, 1 + len(data), param, data)
  File "/usr/local/lib/python3.9/site-packages/zigpy_deconz/api.py", line 313, in _command
    return await asyncio.wait_for(fut, timeout=COMMAND_TIMEOUT)
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
2022-04-29 09:07:25 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:07:30 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 09:07:35 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)

2022-04-29 09:04:32 DEBUG (MainThread) [custom_components.keymaster.binary_sensor] Connected to zwave_js network
2022-04-29 09:04:32 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)

Looks like no code slots are being checked. They would have shown up between these two lines.
Can you check in zwavejs2mqtt that the code slots are infact showing up for the lock?

Excuse my "newbie" status to HA. I'm using zwavejs. Do I also need to install zwavejs2mqtt for this integration work? Did I miss that in my install?

zwavejs2mqtt is the community made addon for zwavejs, you run one or the other not both.

zwavejs2mqtt has a seperate UI to help facilitate troubleshooting, there are steps on flipping to the other addon here.

I'll work on converting that over this after work and let you know what happens. Again, truly appreciate your help!

I got mine working by removing all the locks, uninstalling keymaster, reboot, pairing the locks again in legacy secure mode, reinstalling keymaster and adding the locks back. I then made sure all the codes for each lock matched and was able to remove/re-add codes.
I looked through the logs and couldn't find any keymaster errors before doing the above.

edit: FYI these are all BE469ZP locks

js only. When adding a device there is a link you click to get more options. I added the device then installed keymaster, I don't think the order matters, the zwave linking does, also it looks like keymaster will not update the lock if the codes mismatch, you must setup the lock with the existing codes in keymaster, then you can change them, or it appears that way for me...

image
image

I'm curious about your statement of adding the existing codes in.

I have reset the lock during this process so the only codes currently in the lock are the 2 it comes with. Are you saying I need to add those into code slot 1 and 2 in keymaster or should they be found?

@tommywatson - Thanks for the help. I removed everything and reinstalled with the suggestions you listed above. Same issue.

@firstof9 - The log looks a little different now though to me, but appears to still not be checking the code slots. That said, I do see an entity for each code slot under keymaster integration, but they all say unavailable. Here's the log after a restart:

2022-04-29 20:02:23 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-04-29 20:02:23 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration keymaster which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-04-29 20:03:11 INFO (MainThread) [custom_components.keymaster] Version v0.0.79 is starting, if you have any issues please report them here: https://github.com/FutureTense/keymaster
2022-04-29 20:03:11 DEBUG (MainThread) [custom_components.keymaster.binary_sensor] Connected to zwave_js network
2022-04-29 20:03:11 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:16 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:16 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 367, in _handle_entity_registry_updated
    await self._sync_helper(to_update, to_remove)
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 311, in _sync_helper
    await self.async_get_access_token()
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 173, in async_get_access_token
    raise alexa_errors.RequireRelink
homeassistant.components.alexa.errors.RequireRelink
2022-04-29 20:03:16 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 367, in _handle_entity_registry_updated
    await self._sync_helper(to_update, to_remove)
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 311, in _sync_helper
    await self.async_get_access_token()
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 173, in async_get_access_token
    raise alexa_errors.RequireRelink
homeassistant.components.alexa.errors.RequireRelink
2022-04-29 20:03:16 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 367, in _handle_entity_registry_updated
    await self._sync_helper(to_update, to_remove)
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 311, in _sync_helper
    await self.async_get_access_token()
  File "/usr/src/homeassistant/homeassistant/components/cloud/alexa_config.py", line 173, in async_get_access_token
    raise alexa_errors.RequireRelink
homeassistant.components.alexa.errors.RequireRelink
2022-04-29 20:03:21 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:26 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:31 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:36 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:41 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:46 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:51 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:03:56 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:04 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:09 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:14 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:19 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:24 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:29 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:34 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:39 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:44 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-04-29 20:04:49 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)

It should be saying stuff like "Code slot 1: xxxx" where the xxxx would be your code.

Would you recommend switching to zwavejs2mqtt to see if that helps? I'm not sure I understand why that would make a difference, but it's definitely not working right now.

It would definitely help troubleshoot easier due to the builtin UI

Are you saying I need to add those into code slot 1 and 2 in keymaster or should they be found?
Yeah, you need to put the two codes into the slots for keymaster, at least that's what seems to be going on in my installation, also if you're planning on using more than 4 digits, you have to change it in the lock, that can be a source of frustration.

I tried that. And once enabled, the status stayed as adding. Something else is getting mixed up because all of the entities for the key slots that are generated with the keymaster integration are showing as unavailable.

I'm going to try to switch over to zwavejs2mqtt as @firstof9 suggested and see if there is better troubleshooting information in via that route.

I'm curious, does the device info show up correctly when you look at it through config->devices? And do you see the sensors?

If I go to config->devices I see a device called "keymaster." I do not see any sensors listed under the devices. If I go to config->entities I see a bunch of entities with the name: front_door_lock: Code Slot X. All of those have a red filled in circle with an exclamation point in them. When I hover over that icon it says "Unavailable".

EDIT: I also see bunch related to "keymaster" that have a icon that looks like a circle made out of an arrow and an exclamation point in the middle. When I hover over that it says "Restored"

I wonder if this isn't your problem, your device wasn't interviewed correctly? If I go to Configuration->Devices then select Devices from the top line and search for one of my locks, I see the correct model and the sensors listed, if it doesn't show up correctly Keymaster wont work...

image

@tommywatson I have reinterviewed the device a few times, but I'm definitely seeing some different sensors.
Untitled

It looks like you have interviewed it in the highest security mode, I could never get that to work, if you check my screenshot above my device is in legacy mode. I'd suggest you remove the device from zwave, then adding it again using legacy mode.

#270 (comment)

@firstof9 - I switched everything over to zwavejs2mqtt last night and this morning. I reinstalled keymaster integration and I'm not seeing anything keymaster related in zwavejs2mqtt. That being said, I could be looking in the wrong spot. What should be seeing here?

Also, after reinstalling keymaster, I looked at the code slot entities that are created and they are all showing as unavailable still.

Check under the usercodes section for your lock and see if anything's listing.

No usercodes is going to be your issue, fix that and everything will fall into place.

What you are describing sounds like connectivity issues, give the troubleshooting from zwave-js a shot.

https://zwave-js.github.io/node-zwave-js/#/troubleshooting/connectivity-issues

Thanks Chris. Sorry to keep stringing this along. I'll try some of the connectivity trouble shooting to see if that helps. Are you saying that the connectivity issues might be what's causing the user codes not to come in?

I did one last test before I removed the integration and attempted to start over again. I went to the lock and deleted the two user codes the came with the device. I did this from the physical device. I then put the one of the codes in code slot 1 and the other in code slot 2 on the lovelace dashboard and clicked enable on each (both said, "adding"). Then I programmed those 2 codes into the physical lock and both suddenly showed as "Pin Status - Connected" on the lovelace dashboard. I thought maybe that solved the issues!

I then added a code on the lovelace dashboard in slot 3 and clicked enable. The PIN status is showing as "Adding" and I got a notification in HA that says "front_door_lock LOCK MANAGER
You changed the PIN for front_door_lock code slot 3. Please enable it in order to make it active." The code however, does not work at the door. If I program the code into to the physical lock as well, it shows as "Pin Status - Connected" and works.

Before I was explaining that the entities created by the keymaster integration were showing as "Unavailable." What's interesting is that now the code slot 1 entity and code slot 3 entity are showing as just fine the others are still "Unavailable." This leads me to believe it's not a connectivity issue. I'm clearly missing a step somewhere.

If this command class in zwavejs2mqtt is missing a codeslot:
image

you will get the "unavailable" status for the code slots in HA.

Well, I definitely do not have that command class! I'll work through the troubleshooting steps you provided and try to start over again.

I truly appreciate yours and @tommywatson help with this. I'm about ready to just reload the lock in Smartthings and use that integration, but I really would rather not do that!

Usually this occurs when the interview process can't complete fully, and most of that time it's due to a poor connection/connectivity issues. Those steps should help.

I'm at a loss! I went through the troubleshooting steps, added a usb extension to the zwave controller I am using (Zooz ZST10-700). I excluded the lock and re-added it with the lock sitting within 3 inches of the controller. I've tried using S2 security, I've tried using S0 security.

The only command classes in zwavejs2mqtt I can get to show up are "Door Lock v2", "Manufacturer Specific v1", "Version v2", "Configuration v1", and "Battery v1". If I re-interview the lock, it shows up as unknown manufacturer in zwavejs2mqtt all of the command classes become "v0". Never have I seen the "User Code" command class mentioned. The only thing I see close to this is under "Configuration v1" and I see "[26-112-0-6] User Slot Bit Field". This is currently blank and underneath it says "Occupied slots for User Codes (Default: 0)".

Ultimately, the lock will lock and unlock in HA just fine. What I don't have is the ability to set a code without being at the physical lock which is something I have needed to do in the past with SmartThings. I'd really like to get this keymaster integration to work, but it seems as though my lock is not communicating properly with the zwave controller.

I am unsure, you may need to ask Al on HA Discord about the UserCode command class not showing up.

@firstof9 and @tommywatson - I think I owe you guys a drink at a minimum!

Persistence has paid off and I finally have this working! I think the step I was missing was restarting HA after excluding the lock from the zwave network and before I readded it back in. I did that and again moved the zwave controller right next to the lock for the inclusion and the "User Code" command class showed up and everything worked perfectly! I can't thank you both enough! It even works with S2 security! It clearly wasn't completing the interview process correctly before.

Reinstalled keymaster, added the codes I already had in the lock, they synced up immediately, and was able to add a new code no problem. Tested it out and the worked too.

Thank you both again!

👍
That's great news, congrats!

Hello! A fellow BE469ZP user also getting through this hurdle haha. I am in the process of re-adding my lock to my HA and in the process of reconfiguring Keymaster. One field I have never been fully sure about in the config screen is this field here:
door sensor

Does this option effect which features become available in the Dashboard? I have tried a few and some seem to allow certain UI elements to work so I have been trying quite a few. Is there a for sure one of these options I should be using for this lock? Thanks for any tips!

Use binary_sensor.fake unless you have a sensor setup to monitor if your door is open/closed.

Ok I think that's what I first used. Going through a full restart of this process to see if I can get it work again

Ok so attempting the Z-Wave JS: clear a usercode from a lock and any service I call using this system gives me a failed: Unknown Error.

Check your home-assiatant.log

File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 32, in get_code_slot_value
raise NotFoundError(f"{property_name} for code slot {code_slot} not found")
zwave_js_server.exceptions.NotFoundError: userIdStatus for code slot 1 not found
2022-05-10 17:26:42 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547387693664] Error handling message: Unknown error (unknown_error)

I think it's still related to the lack of unique ID that is still causing the issue with the UI communicating with the status of the door codes

Your code slots are missing, fix that and you're set.

door sensor

I have code slots set to 4, and I have 4 Code tiles on my dashboard.

No, I'm referring to fixing your zwavejs issue.

So you are saying I need to add code slots to my Z-Wave.js integration? I'm not sure I understand what you mean.

I can confirm I can call other service dev tool commands like ping and refresh values to the lock, those return a green check mark. but trying to access any codes or code slots still has the unknown error. Additionally, all 4 of my keymaster entity codes still have the unavailable ! alert status

Sounds like the same issue I was having above. And your currently describing exactly what I was and was not able to do. Ultimately, it came down to the interview process, that appeared to complete properly every time, but wasn't.

What I ended up having to do (multiple times), was to exclude the lock, restart HA (missed this step and wasn't able to get it to work until I did this step), re-add the lock. I had to move my controller as close as possible to the lock for the interview to complete entirely. Once the interview completed, try running your dev tool commands for the user codes. If you get the error again, it didn't complete the interview process and you start this cycle over again. Don't forget the restart of HA between the exclude and re-include steps.

Once those dev tool commands work for a user code, you can be pretty confident that the interview completed correctly and then you can continue with the keymaster install. I ended up switching over to zwavejs2mqtt at the suggestion of @firstof9 which definitely provide some more detail on inclusion. If your using that, it is much easier to tell when the code slots have pulled in versus trial and error.

OK cool thanks for the tip, my Z-wave seemed pretty close to the door already and I was getting all green check marks on the interview process so i thought maybe it was good enough. I have a USB extension cable i can use and I'll try this again tomorrow. Do you have a link to the Zwavejs2mqtt setup? I'll definitely look into that as well. thanks for the tips.

ok i have setup my HA Z-wave adapter to be very close (nearly touching) to the lock to attempt to re-interview. I removed Keymaster and removed the lock from my z-wave.js from the collection. Rebooted the HA PI and even factory reset my lock just to start from scratch.

To begin the connection I started the inclusion mode on HA. I used the programming code method of setting the lock into inclusion mode and started the interview. The Z-Wave adapter remained close to the lock the entire interview and I received all green check marks to complete the interview. I proceeded to try to use the Developer tools window to send code setting and clearing commands but after 3 attempts of this whole process, I still can't get the code slots to be identifiable.

I'm pretty sure I'm completing the setup steps discovered in this thread correctly, so I'm trying to think of anything else to try. I don't think the Zwavejs2mqtt won't work unless I can successfully connect to a code slot on the lock correct? Should I try reinstalling my Zwave.js integration? Any tips would be awesome thank you

Do not remove the integration. Do however switch to zwavejs2mqtt.

alright i have zwavejs2mqtt setup and re-interviewed the lock through Mqtt dashboard and everything looks good from an interview standpoint. Is it from this dashboard that I attempt to change codes? I haven't found a good guide yet on using this method for changing door codes, so im not sure where to go from this initial setup point.

looking through the Z-Wave JA Config DB Browser linked in the MQTT dashboard, i found the parameter for number of User Codes. By default it's set to 0, so I set it to 4 and it said it successfully updated. However in the dashboard, that value then changes to some big 8 digit value after the update completes, and upon trying to manually set a code to slot 3, i continue to have the same error adding or removing codes through the Developer Tools Service commands. Is there a way to set codes within the MQTT dashboard that would still work when this other method does not?

Open the "User Codes" command class and see if anything is listing, example screenshot:
image

I'm not seeing that command class on my interface, that would have been a very obvious spot to look had i had that tho hahaha
door sensor
.

Once you solve this you'll be in business, try a re-interview.
Your "Configuration vundefined" is concerning, either the interview went poorly and you have some RF issues, or the hardware is having issues.

Ok I guess it just comes down to a complete interview. I'll keep trying to some more to see if it happens. Someone showed thier logs of the interview and showed that the sections for the codes times out. I'd like to know how to see that info to more easily somfirm the interview was successful or not. Hopefully I can eventually get a solid interview soon.

In zwavejs2mqtt, click Settings on the left then enable logging like pictured and press the Save (scroll to the very bottom on the right) button.

image
image

You can then view the log from the Store button on the left menu, the log will have the current date on it.

image

Finally made a smidge of progress. I finally managed to get the UserCode V1 command class showing. However when I try to set a code from the dashboard i get the error message in red. If I remove code 2 and replace it with a new value on the lock itself, the code shows up in the dashboard. So i have maybe 1 way communication with a single user code slot? is this just another case of not a complete handshake, or is this salvageable?
error code
user code

trying to edit the user slot bit field in another command class to change how many user codes i can store, and after saying success it returns to this crazy big number
user slot bit fied
.

yeah i added a third code just now, from the lock and it added a second user code field on the dashboard. I have user code 1 (which was code 2 on my instruction manual) and now code 3 with a random code i typed in. I can try deleting the other default code and see if that opens up that slot. I still can't change them from the dash board though.

OK, we really need to figure out a better way to beat this bug haha I continued banging my head against this process over and over, and finally i got access to all 30 User code slots! I think the trick was I Included the lock with Legacy S0 mode and that worked. Although I distinctly remember trying that before and it didn't work. The Z-Wave + indicator on the lock shows a Red "-" indicating that it did not detect the Z-wave + status, but I'm guessing the S2 security is needed for that to be detected? The battery level indications are all not functioning either, which makes me wonder if using Legacy is worth it if I can't get the battery status. Is there a way I can get these other functions working with S0 Legacy mode?

Ah, looks like using the refresh command at least got the battery indicator back up and running that's good. As for having the Z-Wave + detected or not, I'm not really sure if that is necessary? Any benefits to having that properly detected?

well in any case, thanks all for helping me get this setup, I certainly learned a lot more with this experience than if it was simple plug and play. You all rock!

new to keymaster.... have a BE469ZP that is stuck on adding the code.
image

I would hop into the Developer tools/services and see if you can successfully send code update/clear commands from there first. I found that tool to be easier to determine if the lock is accepting commands than using Key master. Once you know you can manually send commands then Keymaster should start working normally. Do you have Zwavejs2MQTT installed? might be mandatory for this lock.

will give that a try and report back...
I was able to add my 2nd lock BE599 and it is working fine.
However, unsure what the "notifications" enabled is supposed to do.... or how it actually sends notifications to/where? (I never get them).

If parent door is selected... shouldn't it pull over all the config from that door so I dont have to setup the next door?

I have 2 issues...
FE469ZP will not set from the Developer Tools

BE599 will not set from the Developer Tools
tried adding a code to slot 5 on my BE599 lock (garage door).... shows success, but nothing is in the panel for it being actually configured
image

Also set the log to DEBUG
image

2022-05-24 11:05:02 INFO (MainThread) [homeassistant.helpers.script.websocket_api_script] websocket_api script: Running websocket_api script
2022-05-24 11:05:02 INFO (MainThread) [homeassistant.helpers.script.websocket_api_script] websocket_api script: Executing step call service
2022-05-24 11:05:02 DEBUG (MainThread) [custom_components.keymaster] Add Code service: <ServiceCall keymaster.add_code (c:0180f70773da822fd69553b3d298d1a1): entity_id=lock.garage_door_lock, code_slot=5, usercode=2345>
2022-05-24 11:05:02 DEBUG (MainThread) [custom_components.keymaster.services] Attempting to call set_usercode...
2022-05-24 11:05:03 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 1
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Utilizing BE469 work around code.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 2
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Utilizing BE469 work around code.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 3
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Utilizing BE469 work around code.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 4
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Utilizing BE469 work around code.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 5
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Utilizing FE599 work around code.
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 6 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 7 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 8 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 9 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 10 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 11 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 12 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 13 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 14 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 15 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 16 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 17 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 18 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 19 not enabled
2022-05-24 11:05:06 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.002 seconds (success: True)
2022-05-24 11:05:08 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)

Nothing present in panel afterwards... but If I set from the panel, then it works.
image

i thought you were testing your BE469ZP lock? Did this work for that lock?

Get this on the BE469ZP
image

image

Nothing present in panel afterwards

You have to fill that data in, issuing the command just verifies the lock accepted the command. The UI doesn't populate from the lock, especially since the BE469 and FE599 report * for the code and do not follow the zwave spec properly.

2022-05-24 11:10:21 DEBUG (MainThread) [custom_components.keymaster.services] Attempting to call set_usercode...
2022-05-24 11:10:21 ERROR (MainThread) [custom_components.keymaster.services] Error calling zwave_js.set_lock_usercode service call: userCode for code slot 5 not found
2022-05-24 11:10:21 ERROR (MainThread) [homeassistant.helpers.script.websocket_api_script] websocket_api script: Error executing script. Unexpected error for call_service at pos 1: userCode for code slot 5 not found
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 447, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 680, in _async_call_service_step
    await service_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1627, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1664, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/config/custom_components/keymaster/__init__.py", line 224, in _add_code
    await add_code(hass, entity_id, code_slot, usercode)
  File "/config/custom_components/keymaster/services.py", line 155, in add_code
    await call_service(
  File "/config/custom_components/keymaster/services.py", line 94, in call_service
    raise err
  File "/config/custom_components/keymaster/services.py", line 89, in call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1627, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1664, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 697, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 677, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 964, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 714, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/zwave_js/lock.py", line 129, in async_set_lock_usercode
    await set_usercode(self.info.node, code_slot, usercode)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 112, in set_usercode
    value = get_code_slot_value(node, code_slot, LOCK_USERCODE_PROPERTY)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 32, in get_code_slot_value
    raise NotFoundError(f"{property_name} for code slot {code_slot} not found")
zwave_js_server.exceptions.NotFoundError: userCode for code slot 5 not found
2022-05-24 11:10:21 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140589140972544] Error handling message: Unknown error (unknown_error)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response
    await func(hass, connection, msg)
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 626, in handle_execute_script
    await script_obj.async_run(msg.get("variables"), context=context)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1513, in async_run
    await asyncio.shield(run.async_run())
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 405, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 449, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 472, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 447, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 680, in _async_call_service_step
    await service_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1627, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1664, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/config/custom_components/keymaster/__init__.py", line 224, in _add_code
    await add_code(hass, entity_id, code_slot, usercode)
  File "/config/custom_components/keymaster/services.py", line 155, in add_code
    await call_service(
  File "/config/custom_components/keymaster/services.py", line 94, in call_service
    raise err
  File "/config/custom_components/keymaster/services.py", line 89, in call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1627, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1664, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 697, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 677, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 964, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 714, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/zwave_js/lock.py", line 129, in async_set_lock_usercode
    await set_usercode(self.info.node, code_slot, usercode)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 112, in set_usercode
    value = get_code_slot_value(node, code_slot, LOCK_USERCODE_PROPERTY)
  File "/usr/local/lib/python3.9/site-packages/zwave_js_server/util/lock.py", line 32, in get_code_slot_value
    raise NotFoundError(f"{property_name} for code slot {code_slot} not found")
zwave_js_server.exceptions.NotFoundError: userCode for code slot 5 not found
2022-05-24 11:10:23 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)
2022-05-24 11:10:25 INFO (MainThread) [homeassistant.components.websocket_api.http.connection] [140588839733856] Connection closed by client
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 1
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Utilizing BE469 work around code.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 2
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Utilizing BE469 work around code.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 3
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Utilizing BE469 work around code.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 4
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Utilizing BE469 work around code.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Ignoring code slot with * in value for code slot 5
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Work around code in use.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Utilizing FE599 work around code.
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 6 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 7 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 8 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 9 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 10 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 11 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 12 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 13 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 14 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 15 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 16 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 17 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 18 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] DEBUG: Code slot 19 not enabled
2022-05-24 11:10:26 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.002 seconds (success: True)
2022-05-24 11:10:28 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.000 seconds (success: True)