Multiprotocol Add-On Crashing

bambi14 commented 9 months ago

Describe the issue you are experiencing

About 1-2 hours after restarting Home Assistant, the Multiprotocol add-on crashes. This issue began after updating to Multiprotocol version 2.4.3. No manual configuration changes were made on my end. The current workaround was to enable the watchdog to restart the Multiprotocol addon when it crashes.

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Which add-on are you reporting an issue with?

Silicon Labs Multiprotocol

What is the version of the add-on?

2.4.3

Steps to reproduce the issue

Updated to version 2.4.3.
The addon crashes with no intervention

System Health information

## System Information

version | core-2024.1.2
-- | --
installation_type | Home Assistant OS
dev | false
hassio | true
docker | true
user | root
virtualenv | false
python_version | 3.11.6
os_name | Linux
os_version | 6.1.71-haos
arch | x86_64
timezone | America/New_York
config_dir | /config

<details><summary>Home Assistant Community Store</summary>

GitHub API | ok
-- | --
GitHub Content | ok
GitHub Web | ok
GitHub API Calls Remaining | 5000
Installed Version | 1.33.0
Stage | running
Available Repositories | 1370
Downloaded Repositories | 13

</details>

<details><summary>Home Assistant Cloud</summary>

logged_in | false
-- | --
can_reach_cert_server | ok
can_reach_cloud_auth | ok
can_reach_cloud | ok

</details>

<details><summary>Home Assistant Supervisor</summary>

host_os | Home Assistant OS 11.4
-- | --
update_channel | stable
supervisor_version | supervisor-2023.12.0
agent_version | 1.6.0
docker_version | 24.0.7
disk_total | 30.8 GB
disk_used | 6.7 GB
healthy | true
supported | true
board | ova
supervisor_api | ok
version_api | ok
installed_addons | Duck DNS (1.15.0), Studio Code Server (5.15.0), Mosquitto broker (6.4.0), Matter Server (5.0.2), Terminal & SSH (9.8.1), Silicon Labs Multiprotocol (2.4.3), File editor (5.7.0)

</details>

<details><summary>Dashboards</summary>

dashboards | 7
-- | --
resources | 6
views | 24
mode | storage

</details>

<details><summary>Recorder</summary>

oldest_recorder_run | January 2, 2024 at 10:40 PM
-- | --
current_recorder_run | January 11, 2024 at 9:41 PM
estimated_db_size | 170.61 MiB
database_engine | sqlite
database_version | 3.41.2

</details>

Anything in the Supervisor logs that might be useful for us?

No response

Anything in the add-on logs that might be useful for us?

otbr-agent[300]: 00:00:00.196 [N] Mle-----------: Role disabled -> detached
otbr-agent[300]: 00:00:00.198 [N] Platform------: [netif] Changing interface state to up.
otbr-agent[300]: 00:00:00.215 [W] Platform------: [netif] ADD [U] fe80:0:0:0:a085:be66:9e98:ea89 failed (InvalidArgs)
otbr-agent[300]: 00:00:00.215 [W] Platform------: [netif] Failed to process event, error:InvalidArgs
otbr-agent[300]: 00:00:00.216 [W] Platform------: [netif] ADD [U] fd7c:f176:af3f:19d2:39ea:badc:584e:2315 failed (InvalidArgs)
otbr-agent[300]: 00:00:00.216 [W] Platform------: [netif] Failed to process event, error:InvalidArgs
otbr-agent[300]: 00:00:00.216 [W] Platform------: [netif] ADD [U] fd7c:f176:af3f:19d2:0:ff:fe00:5000 failed (InvalidArgs)
otbr-agent[300]: 00:00:00.216 [W] Platform------: [netif] Failed to process event, error:InvalidArgs
s6-rc: info: service otbr-agent successfully started
s6-rc: info: service otbr-agent-rest-discovery: starting
[08:43:09] INFO: Successfully sent discovery information to Home Assistant.
s6-rc: info: service otbr-agent-rest-discovery successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
Listening on port 9999 for connection...
Accepting connection.
otbr-agent[300]: 00:00:12.144 [N] Mle-----------: RLOC16 5000 -> fffe
otbr-agent[300]: 00:00:12.148 [W] Platform------: [netif] Failed to process request#5: Operation not supported
otbr-agent[300]: 00:00:12.513 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
otbr-agent[300]: 00:00:13.606 [N] Mle-----------: RLOC16 fffe -> c807
otbr-agent[300]: 00:00:13.611 [N] Mle-----------: Role detached -> child
otbr-agent[300]: 00:00:13.637 [W] Platform------: [netif] ADD [U] fd7c:f176:af3f:19d2:0:ff:fe00:c807 failed (InvalidArgs)
otbr-agent[300]: 00:00:13.637 [W] Platform------: [netif] Failed to process event, error:InvalidArgs
otbr-agent[300]: 00:00:15.850 [W] Platform------: [netif] ADD [U] fd7c:551:6bda:1:8cc0:6701:96e1:9cec failed (InvalidArgs)
otbr-agent[300]: 00:00:15.850 [W] Platform------: [netif] Failed to process event, error:InvalidArgs
Accepted connection 8.
otbr-agent[300]: 00:00:35.815 [W] Platform------: [netif] ADD [U] fd7c:f176:af3f:19d2:0:ff:fe00:fc10 failed (InvalidArgs)
otbr-agent[300]: 00:00:35.815 [W] Platform------: [netif] Failed to process event, error:InvalidArgs
otbr-agent[300]: 00:00:51.161 [N] Mle-----------: RLOC16 c807 -> 5000
otbr-agent[300]: 00:00:51.165 [N] Mle-----------: Role child -> router
otbr-agent[300]: 00:00:51.165 [N] Mle-----------: Partition ID 0x7dbd5b8b
otbr-agent[300]: 00:00:51.167 [W] Platform------: [netif] Failed to process request#9: Operation not supported
otbr-agent[300]: 00:00:51.167 [W] Platform------: [netif] Successfully added an external route ::/0 in kernel
otbr-agent[300]: 00:00:51.193 [W] Platform------: [netif] Failed to process request#10: File exists
otbr-agent[300]: 00:00:51.193 [W] Platform------: [netif] Failed to process request#11: Operation not supported
otbr-agent[300]: 00:00:51.427 [W] Platform------: [netif] Successfully deleted an external route ::/0 in kernel
otbr-agent[300]: 00:00:51.447 [W] Platform------: [netif] Failed to process request#13: Operation not supported
otbr-agent[300]: 00:00:54.382 [N] Ip6-----------: Failed to find valid route for: fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec
otbr-agent[300]: 00:00:56.146 [N] MeshForwarder-: Dropping (reassembly queue) IPv6 UDP msg, len:154, chksum:28d3, ecn:no, sec:yes, error:ReassemblyTimeout, prio:net, rss:-75.0, radio:15.4
otbr-agent[300]: 00:00:56.146 [N] MeshForwarder-:     src:[fe80:0:0:0:24de:32ef:b878:b9e3]:19788
otbr-agent[300]: 00:00:56.146 [N] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
otbr-agent[300]: [NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!
otbr-agent[300]: 00:00:56.343 [W] Platform------: [netif] ADD [U] fd7c:f176:af3f:19d2:0:ff:fe00:fc38 failed (InvalidArgs)
otbr-agent[300]: 00:00:56.344 [W] Platform------: [netif] Failed to process event, error:InvalidArgs
otbr-agent[300]: 00:00:56.346 [W] Platform------: [netif] Failed to process request#16: File exists
otbr-agent[300]: 00:00:56.346 [W] Platform------: [netif] ADD [U] fd7c:f176:af3f:19d2:0:ff:fe00:fc11 failed (InvalidArgs)
otbr-agent[300]: 00:00:56.346 [W] Platform------: [netif] Failed to process event, error:InvalidArgs
otbr-agent[300]: 00:00:56.347 [W] Platform------: [netif] Failed to process request#18: File exists
otbr-agent[300]: 00:01:00.130 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:65f2, ecn:no, sec:yes, error:AddressQuery, prio:low, radio:all
otbr-agent[300]: 00:01:00.130 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:60695
otbr-agent[300]: 00:01:00.130 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:01:49.183 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[300]: 00:01:49.183 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:182, chksum:a13c, ecn:no, to:0xc800, sec:yes, error:ChannelAccessFailure, prio:low, radio:15.4
otbr-agent[300]: 00:01:49.183 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:56775
otbr-agent[300]: 00:01:49.183 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:aa0a:aba2:d333:30fb]:5683
otbr-agent[300]: 00:01:49.440 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[300]: 00:01:49.684 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[300]: 00:01:51.651 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[300]: 00:01:51.652 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:182, chksum:a13c, ecn:no, to:0xc800, sec:yes, error:ChannelAccessFailure, prio:low, radio:15.4
otbr-agent[300]: 00:01:51.652 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:56775
otbr-agent[300]: 00:01:51.652 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:aa0a:aba2:d333:30fb]:5683
otbr-agent[300]: 00:02:25.156 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:b979, ecn:no, sec:yes, error:AddressQuery, prio:low, radio:all
otbr-agent[300]: 00:02:25.156 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:56822
otbr-agent[300]: 00:02:25.156 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:02:25.156 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:b979, ecn:no, sec:yes, error:AddressQuery, prio:low, radio:all
otbr-agent[300]: 00:02:25.156 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:56822
otbr-agent[300]: 00:02:25.156 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:02:29.596 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:b979, ecn:no, sec:yes, error:Drop, prio:low, radio:all
otbr-agent[300]: 00:02:29.597 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:56822
otbr-agent[300]: 00:02:29.597 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:03:53.146 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:8b8c, ecn:no, sec:yes, error:AddressQuery, prio:low, radio:all
otbr-agent[300]: 00:03:53.146 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:41710
otbr-agent[300]: 00:03:53.146 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:03:53.455 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:8b8c, ecn:no, sec:yes, error:Drop, prio:low, radio:all
otbr-agent[300]: 00:03:53.455 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:41710
otbr-agent[300]: 00:03:53.455 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:05:21.093 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:21e7, ecn:no, sec:yes, error:AddressQuery, prio:low, radio:all
otbr-agent[300]: 00:05:21.093 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:55329
otbr-agent[300]: 00:05:21.093 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:05:21.160 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:21e7, ecn:no, sec:yes, error:Drop, prio:low, radio:all
otbr-agent[300]: 00:05:21.160 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:55329
otbr-agent[300]: 00:05:21.160 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:05:25.416 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:21e7, ecn:no, sec:yes, error:Drop, prio:low, radio:all
otbr-agent[300]: 00:05:25.416 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:55329
otbr-agent[300]: 00:05:25.416 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:06:47.434 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:c80d, ecn:no, sec:yes, error:Drop, prio:low, radio:all
otbr-agent[300]: 00:06:47.434 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:40093
otbr-agent[300]: 00:06:47.434 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:06:50.149 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:c80d, ecn:no, sec:yes, error:Drop, prio:low, radio:all
otbr-agent[300]: 00:06:50.149 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:40093
otbr-agent[300]: 00:06:50.149 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:08:18.094 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:07bb, ecn:no, sec:yes, error:AddressQuery, prio:low, radio:all
otbr-agent[300]: 00:08:18.094 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:34717
otbr-agent[300]: 00:08:18.094 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:08:18.180 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:07bb, ecn:no, sec:yes, error:Drop, prio:low, radio:all
otbr-agent[300]: 00:08:18.180 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:34717
otbr-agent[300]: 00:08:18.180 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683
otbr-agent[300]: 00:08:23.240 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:94, chksum:07bb, ecn:no, sec:yes, error:Drop, prio:low, radio:all
otbr-agent[300]: 00:08:23.240 [N] MeshForwarder-:     src:[fd7c:551:6bda:1:8cc0:6701:96e1:9cec]:34717
otbr-agent[300]: 00:08:23.240 [N] MeshForwarder-:     dst:[fd7c:551:6bda:1:6fdd:ef0d:d916:e0ec]:5683



### Additional information

When the multiprotocol addon crashes, this causes the ZHA integration to stop working until multiprotocol is restarted.

tieskuh commented 9 months ago

I have the same problem

puddly commented 9 months ago

What devices do you have on your ZigBee and Thread networks? How many? Can you upload a debug log of the addon crashing?

tieskuh commented 9 months ago

This is the debug log when I try to restart the SkyConnect Multiprotocol integration which fails. When I restart HomeAssistant completely, it works again for some time and than fails again.

I have only some Zigbee devices. No thread devices (yet). The problem also happened after upgrading to 2.4.3.

Core
2024.1.2
Supervisor
2023.12.0
Operating System
11.4
Frontend
20240104.0

2024-01-12 15:37:25.169 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.adeo'
2024-01-12 15:37:25.170 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.adeo.color_controller'
2024-01-12 15:37:25.170 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.aduro'
2024-01-12 15:37:25.171 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.aduro.adurolightncc'
2024-01-12 15:37:25.171 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.aurora'
2024-01-12 15:37:25.171 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.aurora.aurora_dimmer'
2024-01-12 15:37:25.171 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.bitron'
2024-01-12 15:37:25.171 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.bitron.thermostat'
2024-01-12 15:37:25.172 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.bosch'
2024-01-12 15:37:25.172 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.bosch.isw_zdl1_wp11g'
2024-01-12 15:37:25.172 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.bosch.motion'
2024-01-12 15:37:25.173 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.cl_3130'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.cl_3157100'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.cl_3300S'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.cl_3305S'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.cl_3310S'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.cl_3321S'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.cl_3460L'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.ias'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.motion'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.centralite.motionandtemp'
2024-01-12 15:37:25.174 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.const'
2024-01-12 15:37:25.175 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.danfoss'
2024-01-12 15:37:25.176 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.danfoss.thermostat'
2024-01-12 15:37:25.177 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.develco'
2024-01-12 15:37:25.178 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.develco.air_quality'
2024-01-12 15:37:25.178 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.develco.heat_alarm'
2024-01-12 15:37:25.178 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.develco.motion'
2024-01-12 15:37:25.178 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.develco.open_close'
2024-01-12 15:37:25.178 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.develco.power_plug'
2024-01-12 15:37:25.178 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.develco.smoke_alarm'
2024-01-12 15:37:25.178 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.echostar'
2024-01-12 15:37:25.180 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.echostar.bell'
2024-01-12 15:37:25.180 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ecolink'
2024-01-12 15:37:25.181 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ecolink.contact'
2024-01-12 15:37:25.181 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.edpwithus'
2024-01-12 15:37:25.182 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.edpwithus.redy_plug'
2024-01-12 15:37:25.182 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.elko'
2024-01-12 15:37:25.183 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.elko.smart_super_thermostat'
2024-01-12 15:37:25.183 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.eurotronic'
2024-01-12 15:37:25.184 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.eurotronic.spzb0001'
2024-01-12 15:37:25.184 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.feibit'
2024-01-12 15:37:25.185 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.feibit.switch'
2024-01-12 15:37:25.185 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.gledopto'
2024-01-12 15:37:25.186 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.gledopto.glc009'
2024-01-12 15:37:25.186 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.gledopto.glc009p'
2024-01-12 15:37:25.186 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.gledopto.gls007z'
2024-01-12 15:37:25.186 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.gledopto.glsd_dimmer'
2024-01-12 15:37:25.186 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.gledopto.soposhgu10'
2024-01-12 15:37:25.187 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.heiman'
2024-01-12 15:37:25.187 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.heiman.smoke'
2024-01-12 15:37:25.188 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.hivehome'
2024-01-12 15:37:25.188 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.hivehome.mot003V0'
2024-01-12 15:37:25.189 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.hivehome.mot003V6'
2024-01-12 15:37:25.189 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.icasa'
2024-01-12 15:37:25.189 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.icasa.iczb_kpd12'
2024-01-12 15:37:25.190 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.icasa.iczb_kpd14s'
2024-01-12 15:37:25.190 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.icasa.iczb_kpd18s'
2024-01-12 15:37:25.190 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.blinds'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.cctlightzha'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.dimmer'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.fivebtnremote'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.fourbtnremote'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.motion'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.motionzha'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.opencloseremote'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.shortcutbtn'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.somrigsmartbtn'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.starkvind'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.symfonisk'
2024-01-12 15:37:25.191 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.symfonisk2'
2024-01-12 15:37:25.192 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.tradfriplug'
2024-01-12 15:37:25.192 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ikea.twobtnremote'
2024-01-12 15:37:25.192 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.iluminize'
2024-01-12 15:37:25.194 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.iluminize.cct'
2024-01-12 15:37:25.194 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.iluminize.dim'
2024-01-12 15:37:25.195 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.imagic'
2024-01-12 15:37:25.196 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.imagic.gs1117s'
2024-01-12 15:37:25.196 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.imagic.im1116s'
2024-01-12 15:37:25.196 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.innr'
2024-01-12 15:37:25.197 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.innr.innr_sp120_plug'
2024-01-12 15:37:25.197 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.innr.innr_sp234_plug'
2024-01-12 15:37:25.197 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.innr.innr_sp240_plug'
2024-01-12 15:37:25.197 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.innr.rs228t'
2024-01-12 15:37:25.197 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.inovelli'
2024-01-12 15:37:25.198 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.inovelli.VZM31SN'
2024-01-12 15:37:25.198 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.inovelli.VZM35SN'
2024-01-12 15:37:25.199 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.inovelli.types'
2024-01-12 15:37:25.199 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.insta'
2024-01-12 15:37:25.199 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.insta.nexentro_pushbutton_interface'
2024-01-12 15:37:25.200 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.keenhome'
2024-01-12 15:37:25.200 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.keenhome.sv02612mp13'
2024-01-12 15:37:25.200 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.keenhome.weather'
2024-01-12 15:37:25.201 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.kof'
2024-01-12 15:37:25.201 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.kof.kof_mr101z'
2024-01-12 15:37:25.201 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.konke'
2024-01-12 15:37:25.202 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.konke.button'
2024-01-12 15:37:25.202 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.konke.magnet'
2024-01-12 15:37:25.202 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.konke.motion'
2024-01-12 15:37:25.202 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.konke.temp'
2024-01-12 15:37:25.202 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lds'
2024-01-12 15:37:25.203 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lds.cctswitch'
2024-01-12 15:37:25.203 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ledvance'
2024-01-12 15:37:25.204 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ledvance.a19rgbw'
2024-01-12 15:37:25.204 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.ledvance.flexrgbw'
2024-01-12 15:37:25.204 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.legrand'
2024-01-12 15:37:25.204 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.legrand.dimmer'
2024-01-12 15:37:25.205 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.legrand.switch'
2024-01-12 15:37:25.205 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lidl'
2024-01-12 15:37:25.205 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lidl.TS0501A'
2024-01-12 15:37:25.206 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lidl.cct'
2024-01-12 15:37:25.206 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lidl.rgbcct'
2024-01-12 15:37:25.206 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lidl.ts011f_plug'
2024-01-12 15:37:25.206 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.linkind'
2024-01-12 15:37:25.207 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.linkind.a001082'
2024-01-12 15:37:25.207 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.linkind.motion'
2024-01-12 15:37:25.207 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lixee'
2024-01-12 15:37:25.208 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lixee.zlinky'
2024-01-12 15:37:25.208 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lutron'
2024-01-12 15:37:25.208 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.lutron.lzl4bwhl01remote'
2024-01-12 15:37:25.209 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.mli'
2024-01-12 15:37:25.209 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.mli.tint'
2024-01-12 15:37:25.209 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.mli.tintE14rgbcct'
2024-01-12 15:37:25.210 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.netvox'
2024-01-12 15:37:25.210 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.netvox.z308e3ed'
2024-01-12 15:37:25.210 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.nodon'
2024-01-12 15:37:25.211 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.nodon.switch'
2024-01-12 15:37:25.211 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.nue'
2024-01-12 15:37:25.211 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.nue.auwz02000'
2024-01-12 15:37:25.212 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.orvibo'
2024-01-12 15:37:25.212 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.orvibo.dimmer'
2024-01-12 15:37:25.212 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.orvibo.motion'
2024-01-12 15:37:25.213 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram'
2024-01-12 15:37:25.213 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.a19rgbw'
2024-01-12 15:37:25.213 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.cla60tw'
2024-01-12 15:37:25.213 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.flexrgbw'
2024-01-12 15:37:25.213 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.gardenpolesrgbw'
2024-01-12 15:37:25.214 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.lightifyx4'
2024-01-12 15:37:25.214 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.osramplug'
2024-01-12 15:37:25.214 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.smartplusac05347'
2024-01-12 15:37:25.214 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.switchmini'
2024-01-12 15:37:25.214 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.osram.tunablewhite'
2024-01-12 15:37:25.214 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.paulmann'
2024-01-12 15:37:25.216 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.paulmann.fourbtnremote'
2024-01-12 15:37:25.216 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.philio'
2024-01-12 15:37:25.216 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.philio.pst03a'
2024-01-12 15:37:25.217 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.philips'
2024-01-12 15:37:25.217 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.philips.motion'
2024-01-12 15:37:25.217 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.philips.rdm001'
2024-01-12 15:37:25.217 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.philips.rom001'
2024-01-12 15:37:25.217 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.philips.rwl022'
2024-01-12 15:37:25.217 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.philips.rwlfirstgen'
2024-01-12 15:37:25.218 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.plaid'
2024-01-12 15:37:25.219 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.plaid.soil'
2024-01-12 15:37:25.219 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.quirk_ids'
2024-01-12 15:37:25.219 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.salus'
2024-01-12 15:37:25.219 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.salus.sp600'
2024-01-12 15:37:25.220 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.samjin'
2024-01-12 15:37:25.220 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.samjin.button'
2024-01-12 15:37:25.220 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.samjin.multi'
2024-01-12 15:37:25.220 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.samjin.multi2'
2024-01-12 15:37:25.221 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sengled'
2024-01-12 15:37:25.221 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sengled.e1e_g7f'
2024-01-12 15:37:25.222 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sercomm'
2024-01-12 15:37:25.222 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sercomm.contact_sensor'
2024-01-12 15:37:25.222 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sercomm.flood_sensor'
2024-01-12 15:37:25.223 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.siglis'
2024-01-12 15:37:25.223 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.siglis.zigfred'
2024-01-12 15:37:25.223 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sinope'
2024-01-12 15:37:25.224 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sinope.light'
2024-01-12 15:37:25.224 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sinope.sensor'
2024-01-12 15:37:25.224 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sinope.switch'
2024-01-12 15:37:25.224 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sinope.thermostat'
2024-01-12 15:37:25.224 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartthings'
2024-01-12 15:37:25.225 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartthings.moisturev4'
2024-01-12 15:37:25.225 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartthings.motion'
2024-01-12 15:37:25.225 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartthings.multi'
2024-01-12 15:37:25.225 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartthings.multiv4'
2024-01-12 15:37:25.225 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartthings.pgc313'
2024-01-12 15:37:25.225 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartthings.pgc314'
2024-01-12 15:37:25.225 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartthings.tag_v4'
2024-01-12 15:37:25.226 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartwings'
2024-01-12 15:37:25.227 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.smartwings.wm25lz'
2024-01-12 15:37:25.227 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sonoff'
2024-01-12 15:37:25.227 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sonoff.button'
2024-01-12 15:37:25.227 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sonoff.snzb01p'
2024-01-12 15:37:25.228 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sourcingandcreation'
2024-01-12 15:37:25.228 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.sourcingandcreation.smart_button'
2024-01-12 15:37:25.228 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.terncy'
2024-01-12 15:37:25.229 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.terncy.cl001'
2024-01-12 15:37:25.229 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.terncy.pp01'
2024-01-12 15:37:25.229 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.terncy.sd01'
2024-01-12 15:37:25.229 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.texasinstruments'
2024-01-12 15:37:25.230 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.texasinstruments.router'
2024-01-12 15:37:25.230 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.thirdreality'
2024-01-12 15:37:25.230 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.thirdreality.button'
2024-01-12 15:37:25.230 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.thirdreality.night_light'
2024-01-12 15:37:25.230 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.thirdreality.switch'
2024-01-12 15:37:25.231 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.thirdreality.vibrate'
2024-01-12 15:37:25.231 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.trust'
2024-01-12 15:37:25.231 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.trust.zpir8000'
2024-01-12 15:37:25.232 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya'
2024-01-12 15:37:25.233 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.air'
2024-01-12 15:37:25.233 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.air.ts0601_air_quality'
2024-01-12 15:37:25.233 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.air.ts0601_smart_air'
2024-01-12 15:37:25.234 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.mcu'
2024-01-12 15:37:25.234 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.sm0202_motion'
2024-01-12 15:37:25.234 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0001_fingerbot'
2024-01-12 15:37:25.234 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts000f_switch'
2024-01-12 15:37:25.234 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts000x'
2024-01-12 15:37:25.234 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts001x'
2024-01-12 15:37:25.234 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0041'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0042'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0043'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0044'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0046'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts004f'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts011f_plug'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts011f_switch'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0121_plug'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0201'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0210'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0211'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0501_fan_switch'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0501b'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0501bs'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_co'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_cover'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_dimmer'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_din_power'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_electric_heating'
2024-01-12 15:37:25.235 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_garage'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_gas'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_haozee'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_illuminance'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_motion'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_rcbo'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_sensor'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_siren'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_smoke'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_switch'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_trv'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_trv_sas'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts0601_valve'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts110e'
2024-01-12 15:37:25.236 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.tuya.ts130f'
2024-01-12 15:37:25.238 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.universalelectronics'
2024-01-12 15:37:25.239 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.universalelectronics.contact_sensor'
2024-01-12 15:37:25.240 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.visonic'
2024-01-12 15:37:25.241 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.visonic.mct340'
2024-01-12 15:37:25.241 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.waxman'
2024-01-12 15:37:25.242 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.waxman.leaksmart'
2024-01-12 15:37:25.242 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xbee'
2024-01-12 15:37:25.244 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xbee.types'
2024-01-12 15:37:25.244 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xbee.xbee3_io'
2024-01-12 15:37:25.244 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xbee.xbee_io'
2024-01-12 15:37:25.244 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi'
2024-01-12 15:37:25.245 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara'
2024-01-12 15:37:25.245 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.ctrl_ln'
2024-01-12 15:37:25.245 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.ctrl_neutral'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.cube'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.cube_aqgl01'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.driver_curtain_e1'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.feeder_acn001'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.illumination'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.light_acn'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.light_aqcn2'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.magnet_ac01'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.magnet_acn001'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.magnet_agl02'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.magnet_aq2'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.motion_ac01'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.motion_ac02'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.motion_agl02'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.motion_agl04'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.motion_aq2'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.motion_aq2b'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.opple_remote'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.opple_switch'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.plug'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.plug_eu'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.plug_maus01'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.relay_c2acn01'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.remote_b186acn01'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.remote_b286acn01'
2024-01-12 15:37:25.246 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.remote_e1'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.remote_h1'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.roller_curtain_e1'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.sensor_ht_agl02'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.sensor_switch_aq3'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.smoke'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.switch_acn047'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.switch_aq2'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.switch_h1_double'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.switch_h1_single'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.switch_t1'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.thermostat_agl001'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.tvoc'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.vibration_aq1'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.water_acn001'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.water_agl02'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.weather'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.aqara.wleak_aq1'
2024-01-12 15:37:25.247 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.mija'
2024-01-12 15:37:25.249 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.mija.motion'
2024-01-12 15:37:25.249 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.mija.sensor_ht'
2024-01-12 15:37:25.249 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.mija.sensor_magnet'
2024-01-12 15:37:25.249 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.mija.sensor_switch'
2024-01-12 15:37:25.249 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.xiaomi.mija.smoke'
2024-01-12 15:37:25.250 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.yale'
2024-01-12 15:37:25.250 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.yale.realliving'
2024-01-12 15:37:25.251 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.zen'
2024-01-12 15:37:25.251 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.zen.thermostat'
2024-01-12 15:37:25.252 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.zhongxing'
2024-01-12 15:37:25.254 DEBUG (MainThread) [zhaquirks] Loading quirks module 'zhaquirks.zhongxing.motion'
2024-01-12 15:37:25.254 DEBUG (MainThread) [homeassistant.components.zha] ZHA storage file does not exist or was already removed
2024-01-12 15:37:25.287 DEBUG (Thread-291) [aiosqlite] executing <function aiosqlite_connect.<locals>.<lambda> at 0x7f07a4cade40>
2024-01-12 15:37:25.287 DEBUG (Thread-291) [aiosqlite] operation <function aiosqlite_connect.<locals>.<lambda> at 0x7f07a4cade40> completed
2024-01-12 15:37:25.288 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA integrity_check', [])
2024-01-12 15:37:25.289 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA integrity_check', []) completed
2024-01-12 15:37:25.290 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchall of sqlite3.Cursor object at 0x7f07a2c6ccc0>)
2024-01-12 15:37:25.290 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchall of sqlite3.Cursor object at 0x7f07a2c6ccc0>) completed
2024-01-12 15:37:25.290 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a2c6ccc0>)
2024-01-12 15:37:25.290 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a2c6ccc0>) completed
2024-01-12 15:37:25.290 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f07a2a62a20>)
2024-01-12 15:37:25.290 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f07a2a62a20>) completed
2024-01-12 15:37:25.290 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA journal_mode = WAL', [])
2024-01-12 15:37:25.291 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA journal_mode = WAL', []) completed
2024-01-12 15:37:25.291 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA synchronous = normal', [])
2024-01-12 15:37:25.291 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA synchronous = normal', []) completed
2024-01-12 15:37:25.292 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA temp_store = memory', [])
2024-01-12 15:37:25.292 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA temp_store = memory', []) completed
2024-01-12 15:37:25.292 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f07a2a62f20>)
2024-01-12 15:37:25.292 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f07a2a62f20>) completed
2024-01-12 15:37:25.292 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA foreign_keys = ON', [])
2024-01-12 15:37:25.292 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA foreign_keys = ON', []) completed
2024-01-12 15:37:25.293 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, "SELECT name FROM sqlite_master WHERE type='table'", [])
2024-01-12 15:37:25.293 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, "SELECT name FROM sqlite_master WHERE type='table'", []) completed
2024-01-12 15:37:25.293 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.294 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.294 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.294 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.294 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>)
2024-01-12 15:37:25.294 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>) completed
2024-01-12 15:37:25.294 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA user_version', [])
2024-01-12 15:37:25.294 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA user_version', []) completed
2024-01-12 15:37:25.295 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchone of sqlite3.Cursor object at 0x7f07ad0b0b40>)
2024-01-12 15:37:25.295 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchone of sqlite3.Cursor object at 0x7f07ad0b0b40>) completed
2024-01-12 15:37:25.295 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>)
2024-01-12 15:37:25.295 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>) completed
2024-01-12 15:37:25.296 DEBUG (MainThread) [zigpy.appdb] Current database version is v12 (table version v12)
2024-01-12 15:37:25.296 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'BEGIN TRANSACTION', [])
2024-01-12 15:37:25.296 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'BEGIN TRANSACTION', []) completed
2024-01-12 15:37:25.296 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'COMMIT', [])
2024-01-12 15:37:25.296 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'COMMIT', []) completed
2024-01-12 15:37:25.297 DEBUG (MainThread) [zigpy.appdb] Loading application state
2024-01-12 15:37:25.297 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM devices_v12', [])
2024-01-12 15:37:25.297 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM devices_v12', []) completed
2024-01-12 15:37:25.297 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.298 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.298 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.298 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.298 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>)
2024-01-12 15:37:25.298 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>) completed
2024-01-12 15:37:25.299 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM node_descriptors_v12', [])
2024-01-12 15:37:25.299 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM node_descriptors_v12', []) completed
2024-01-12 15:37:25.299 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.300 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.301 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.301 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.301 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>)
2024-01-12 15:37:25.301 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>) completed
2024-01-12 15:37:25.301 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM endpoints_v12', [])
2024-01-12 15:37:25.302 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM endpoints_v12', []) completed
2024-01-12 15:37:25.302 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.303 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.303 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.303 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.303 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>)
2024-01-12 15:37:25.303 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>) completed
2024-01-12 15:37:25.304 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM in_clusters_v12', [])
2024-01-12 15:37:25.304 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM in_clusters_v12', []) completed
2024-01-12 15:37:25.304 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.305 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.306 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64)
2024-01-12 15:37:25.306 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07ad0b0b40>, 64) completed
2024-01-12 15:37:25.306 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>)
2024-01-12 15:37:25.307 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07ad0b0b40>) completed
2024-01-12 15:37:25.307 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM out_clusters_v12', [])
2024-01-12 15:37:25.307 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM out_clusters_v12', []) completed
2024-01-12 15:37:25.307 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a2c6ccc0>, 64)
2024-01-12 15:37:25.308 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a2c6ccc0>, 64) completed
2024-01-12 15:37:25.309 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a2c6ccc0>, 64)
2024-01-12 15:37:25.309 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a2c6ccc0>, 64) completed
2024-01-12 15:37:25.309 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a2c6ccc0>)
2024-01-12 15:37:25.309 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a2c6ccc0>) completed
2024-01-12 15:37:25.310 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM attributes_cache_v12 WHERE attrid=4 OR attrid=5', [])
2024-01-12 15:37:25.310 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM attributes_cache_v12 WHERE attrid=4 OR attrid=5', []) completed
2024-01-12 15:37:25.310 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.311 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0000] Attribute id: 4 value: Philips
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0000] Attribute id: 5 value: ROM001
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 5 value: lumi.motion.ac02
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x9ad6:1:0x0000] Attribute id: 4 value: AL001
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x9ad6:1:0x0000] Attribute id: 5 value: WG001-Z01
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0000] Attribute id: 4 value: IKEA of Sweden
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0000] Attribute id: 5 value: TRADFRI on/off switch
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0000] Attribute id: 4 value: IKEA of Sweden
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0000] Attribute id: 5 value: TRADFRI on/off switch
2024-01-12 15:37:25.311 DEBUG (MainThread) [zigpy.appdb] [0x0000:1:0x0000] Attribute id: 5 value: EZSP
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.appdb] [0x0000:1:0x0000] Attribute id: 4 value: Silicon Labs
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0000] Attribute id: 5 value: lumi.motion.ac02
2024-01-12 15:37:25.312 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.312 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.312 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.312 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for Silicon Labs EZSP (e0:79:8d:ff:fe:1d:16:4f)
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2}
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2}
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.tuya.ts0201.MoesTemperatureHumidtySensorWithScreen'>
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2024-01-12 15:37:25.312 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1, 2}
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for Philips ROM001 (00:17:88:01:08:95:6b:27)
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:17:88:01:08:95:6b:27: <class 'zhaquirks.philips.rom001.PhilipsROM001'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.motion.ac02 (54:ef:44:10:00:5a:ab:84)
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.motion_ac02.LumiMotionAC02'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 54:ef:44:10:00:5a:ab:84: <class 'zhaquirks.xiaomi.aqara.motion_ac02.LumiMotionAC02'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.weather (00:15:8d:00:08:ce:48:74)
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:ce:48:74: <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for AL001 WG001-Z01 (e0:79:8d:ff:fe:e4:32:12)
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2, 242}
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2, 242}
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.tuya.ts0201.MoesTemperatureHumidtySensorWithScreen'>
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 242}
2024-01-12 15:37:25.313 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 242}
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 242}
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 242}
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1, 2, 242}
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_magnet.aq2 (00:15:8d:00:08:aa:50:78)
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:aa:50:78: <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.weather (00:15:8d:00:08:c9:41:61)
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:c9:41:61: <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.weather (00:15:8d:00:08:e0:17:08)
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:e0:17:08: <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for IKEA of Sweden TRADFRI on/off switch (94:34:69:ff:fe:60:c6:f6)
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2BtnZLL'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2Btn'>
2024-01-12 15:37:25.314 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 94:34:69:ff:fe:60:c6:f6: <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2Btn'>
2024-01-12 15:37:25.316 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for IKEA of Sweden TRADFRI on/off switch (94:34:69:ff:fe:3a:f7:3a)
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2BtnZLL'>
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2Btn'>
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 94:34:69:ff:fe:3a:f7:3a: <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2Btn'>
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_magnet.aq2 (00:15:8d:00:08:93:8e:bc)
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'>
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:93:8e:bc: <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'>
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.motion.ac02 (54:ef:44:10:00:72:a1:e0)
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.motion_ac02.LumiMotionAC02'>
2024-01-12 15:37:25.317 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 54:ef:44:10:00:72:a1:e0: <class 'zhaquirks.xiaomi.aqara.motion_ac02.LumiMotionAC02'>
2024-01-12 15:37:25.317 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM attributes_cache_v12', [])
2024-01-12 15:37:25.318 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM attributes_cache_v12', []) completed
2024-01-12 15:37:25.318 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.324 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.326 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0000] Attribute id: 4 value: Philips
2024-01-12 15:37:25.326 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0000] Attribute id: 5 value: ROM001
2024-01-12 15:37:25.326 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0001] Attribute id: 32 value: 29
2024-01-12 15:37:25.326 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0001] Attribute id: 33 value: 200
2024-01-12 15:37:25.326 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 1 value: 6
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 5 value: lumi.motion.ac02
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0500] Attribute id: 1 value: 13
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0500] Attribute id: 16 value: e0:79:8d:ff:fe:1d:16:4f
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0001] Attribute id: 49 value: 11
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0001] Attribute id: 51 value: 1
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0400] Attribute id: 0 value: 15052.49978319906
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 258 value: 5
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 268 value: 2
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 338 value: 0
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 274 value: 65578
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0406] Attribute id: 0 value: 0
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0500] Attribute id: 0 value: 0
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 247 value: b'\x01!\xb8\x0b\x03(\x12\x04!\x00\x00\x05!\x01\x00\x08!\x06\x01\n!\xd6\x9a\x0c \x01\x13 \x00\x14 \x00d\x10\x00e! \x00i \x05j \x02k \x00'
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0001] Attribute id: 32 value: 30.0
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0001] Attribute id: 33 value: 129
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 65281 value: b'\x01!\xa9\x0b\x04!\xa8C\x05!\x0b\x00\x06$\x01\x00\x00\x00\x00d)\xf8\x05e!{\x10f+\xac\x93\x01\x00\n!\xd6\x9a'
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0001] Attribute id: 32 value: 29.9
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0001] Attribute id: 33 value: 118
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0402] Attribute id: 0 value: 1525
2024-01-12 15:37:25.327 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0405] Attribute id: 0 value: 4181
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0403] Attribute id: 0 value: 1032
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x9ad6:1:0x0000] Attribute id: 4 value: AL001
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x9ad6:1:0x0000] Attribute id: 5 value: WG001-Z01
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 65281 value: b'\x01!\x95\x0b\x03(\x10\x04!\xa8\x13\x05!;\x00\x06$\x01\x00\x00\x00\x00\n!\x00\x00d\x10\x00'
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0001] Attribute id: 32 value: 29.6
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0001] Attribute id: 33 value: 104
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0002] Attribute id: 0 value: 1600
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 65281 value: b'\x01!w\x0b\x04!\xa8C\x05!\t\x00\x06$\x01\x00\x00\x00\x00d)\x1f\x04e!=\x13f+(\x96\x01\x00\n!\xd6\x9a'
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0001] Attribute id: 32 value: 29.4
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0001] Attribute id: 33 value: 82
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0402] Attribute id: 0 value: 1055
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0405] Attribute id: 0 value: 4925
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0403] Attribute id: 0 value: 1039.76
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 65281 value: b'\x01!\x8b\x0b\x04!\xa8C\x05!\x07\x00\x06$\x01\x00\x00\x00\x00d)\x8f\x06e!\xd6\x10f+\x1a\x95\x01\x00\n!\xd6\x9a'
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0001] Attribute id: 32 value: 29.6
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0001] Attribute id: 33 value: 96
2024-01-12 15:37:25.328 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0402] Attribute id: 0 value: 1679
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0405] Attribute id: 0 value: 4310
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0403] Attribute id: 0 value: 1037.06
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0000] Attribute id: 4 value: IKEA of Sweden
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0000] Attribute id: 5 value: TRADFRI on/off switch
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0020] Attribute id: 0 value: 13200
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0001] Attribute id: 32 value: 26
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0001] Attribute id: 33 value: 42
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0001] Attribute id: 49 value: 10
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0001] Attribute id: 51 value: 1
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0000] Attribute id: 4 value: IKEA of Sweden
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0000] Attribute id: 5 value: TRADFRI on/off switch
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0020] Attribute id: 0 value: 13200
2024-01-12 15:37:25.329 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0001] Attribute id: 32 value: 31
2024-01-12 15:37:25.329 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.331 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0001] Attribute id: 33 value: 200
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0001] Attribute id: 49 value: 10
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0001] Attribute id: 51 value: 1
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0500] Attribute id: 2 value: 0
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0x0000:1:0x0000] Attribute id: 5 value: EZSP
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0x0000:1:0x0000] Attribute id: 4 value: Silicon Labs
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 65281 value: b'\x01!\x9f\x0b\x03(\x0e\x04!\xa8\x13\x05!v\x00\x06$\x01\x00\x00\x00\x00\n!\xd6\x9ad\x10\x01'
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0001] Attribute id: 32 value: 29.8
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0001] Attribute id: 33 value: 111
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0002] Attribute id: 0 value: 1400
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0000] Attribute id: 5 value: lumi.motion.ac02
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0500] Attribute id: 1 value: 13
2024-01-12 15:37:25.332 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0500] Attribute id: 16 value: e0:79:8d:ff:fe:1d:16:4f
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0001] Attribute id: 49 value: 11
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0001] Attribute id: 51 value: 1
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0400] Attribute id: 0 value: 15315.789170422551
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 258 value: 5
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 268 value: 2
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 338 value: 0
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 247 value: b'\x01!\xa0\x0b\x03(\x0c\x04!\x00\x00\x05!\x01\x00\x08!\x06\x01\n!\xd6\x9a\x0c \x01\x13 \x00\x14 \x00d\x10\x00e!"\x00i \x05j \x02k \x00'
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0001] Attribute id: 32 value: 29.8
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0001] Attribute id: 33 value: 111
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0500] Attribute id: 2 value: 0
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 274 value: 65536
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0406] Attribute id: 0 value: 0
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 1 value: 3
2024-01-12 15:37:25.333 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 1 value: 3
2024-01-12 15:37:25.333 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.333 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.334 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.334 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.335 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM unsupported_attributes_v12', [])
2024-01-12 15:37:25.335 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM unsupported_attributes_v12', []) completed
2024-01-12 15:37:25.335 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.336 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.336 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.336 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.337 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.337 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.337 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM groups_v12', [])
2024-01-12 15:37:25.337 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM groups_v12', []) completed
2024-01-12 15:37:25.337 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.338 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.338 DEBUG (MainThread) [zigpy.group] Adding group: 21973, No name group 0x55D5
2024-01-12 15:37:25.338 DEBUG (MainThread) [zigpy.group] Adding group: 0, Default Lightlink Group
2024-01-12 15:37:25.338 DEBUG (MainThread) [zigpy.group] Adding group: 33238, No name group 0x81D6
2024-01-12 15:37:25.339 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.339 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.340 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.340 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.340 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM group_members_v12', [])
2024-01-12 15:37:25.341 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM group_members_v12', []) completed
2024-01-12 15:37:25.341 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.341 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.342 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.342 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.342 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.342 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.343 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM relays_v12', [])
2024-01-12 15:37:25.343 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM relays_v12', []) completed
2024-01-12 15:37:25.343 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.346 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.361 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.361 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.363 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.364 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.365 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM neighbors_v12', [])
2024-01-12 15:37:25.365 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM neighbors_v12', []) completed
2024-01-12 15:37:25.366 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.368 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.369 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.369 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.369 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.369 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.369 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM routes_v12', [])
2024-01-12 15:37:25.369 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM routes_v12', []) completed
2024-01-12 15:37:25.370 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.370 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.371 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.371 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.371 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.371 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.372 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM network_backups_v12 ORDER BY id', [])
2024-01-12 15:37:25.372 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'SELECT * FROM network_backups_v12 ORDER BY id', []) completed
2024-01-12 15:37:25.372 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.373 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.374 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64)
2024-01-12 15:37:25.374 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d66ba40>, 64) completed
2024-01-12 15:37:25.374 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>)
2024-01-12 15:37:25.374 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d66ba40>) completed
2024-01-12 15:37:25.375 DEBUG (MainThread) [zigpy.backups] Adding a new backup NetworkBackup(version=1, backup_time=datetime.datetime(2023, 12, 6, 2, 3, 20, 968712, tzinfo=datetime.timezone.utc), network_info=NetworkInfo(extended_pan_id=3f:73:26:41:1b:59:32:5f, pan_id=0xC280, nwk_update_id=0, nwk_manager_id=0x0000, channel=15, channel_mask=<Channels.ALL_CHANNELS: 134215680>, security_level=5, network_key=Key(key=73:0b:6d:b6:a1:7c:7c:94:cd:ea:9d:cb:d8:d3:97:e0, tx_counter=2734028, rx_counter=0, seq=0, partner_ieee=ff:ff:ff:ff:ff:ff:ff:ff), tc_link_key=Key(key=5a:69:67:42:65:65:41:6c:6c:69:61:6e:63:65:30:39, tx_counter=28672, rx_counter=0, seq=0, partner_ieee=e0:79:8d:ff:fe:1d:16:4f), key_table=[], children=[], nwk_addresses={}, stack_specific={'ezsp': {'hashed_tclk': '795da17ed0c8e1f62dee3951869e5e57'}}, metadata={'ezsp': {'manufacturer': '', 'board': '', 'version': '7.3.1.0 build 0', 'stack_version': 12, 'can_burn_userdata_custom_eui64': False, 'can_rewrite_custom_eui64': True}}, source='bellows@0.36.8'), node_info=NodeInfo(nwk=0x0000, ieee=e0:79:8d:ff:fe:1d:16:4f, logical_type=<LogicalType.Coordinator: 0>, model=None, manufacturer=None, version=None))
2024-01-12 15:37:25.376 DEBUG (MainThread) [zigpy.backups] Adding a new backup NetworkBackup(version=1, backup_time=datetime.datetime(2024, 1, 12, 11, 3, 50, 472966, tzinfo=datetime.timezone.utc), network_info=NetworkInfo(extended_pan_id=3f:73:26:41:1b:59:32:5f, pan_id=0xC280, nwk_update_id=0, nwk_manager_id=0x0000, channel=15, channel_mask=<Channels.ALL_CHANNELS: 134215680>, security_level=5, network_key=Key(key=73:0b:6d:b6:a1:7c:7c:94:cd:ea:9d:cb:d8:d3:97:e0, tx_counter=3072002, rx_counter=0, seq=0, partner_ieee=ff:ff:ff:ff:ff:ff:ff:ff), tc_link_key=Key(key=5a:69:67:42:65:65:41:6c:6c:69:61:6e:63:65:30:39, tx_counter=0, rx_counter=0, seq=0, partner_ieee=e0:79:8d:ff:fe:1d:16:4f), key_table=[], children=[], nwk_addresses={}, stack_specific={'ezsp': {'hashed_tclk': '795da17ed0c8e1f62dee3951869e5e57'}}, metadata={'ezsp': {'stack_version': 13, 'can_burn_userdata_custom_eui64': False, 'can_rewrite_custom_eui64': True}}, source='bellows@0.37.6'), node_info=NodeInfo(nwk=0x0000, ieee=e0:79:8d:ff:fe:1d:16:4f, logical_type=<LogicalType.Coordinator: 0>, model=None, manufacturer=None, version='7.4.0.0 build 0'))
2024-01-12 15:37:25.376 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f079287b100>)
2024-01-12 15:37:25.376 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f079287b100>) completed
2024-01-12 15:37:25.377 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA wal_checkpoint;', [])
2024-01-12 15:37:25.377 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee8a0220>, 'PRAGMA wal_checkpoint;', []) completed
2024-01-12 15:37:25.377 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f079287b100>)
2024-01-12 15:37:25.377 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f079287b100>) completed
2024-01-12 15:37:25.377 DEBUG (Thread-291) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Connection object at 0x7f07ee8a0220>)
2024-01-12 15:37:25.379 DEBUG (Thread-291) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Connection object at 0x7f07ee8a0220>) completed
2024-01-12 15:37:26.480 DEBUG (MainThread) [homeassistant.components.zha] Trigger cache: {'13d326d3640bf0596c9979872604eb22': ('e0:79:8d:ff:fe:1d:16:4f', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}}), '803e15ec7413de55b10799fc75cc0061': ('00:17:88:01:08:95:6b:27', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}, ('remote_button_short_press', 'turn_on'): {'command': 'on_press'}, ('remote_button_long_press', 'turn_on'): {'command': 'on_hold'}, ('remote_button_double_press', 'turn_on'): {'command': 'on_double_press'}, ('remote_button_triple_press', 'turn_on'): {'command': 'on_triple_press'}, ('remote_button_quadruple_press', 'turn_on'): {'command': 'on_quadruple_press'}, ('remote_button_quintuple_press', 'turn_on'): {'command': 'on_quintuple_press'}, ('remote_button_short_release', 'turn_on'): {'command': 'on_short_release'}, ('remote_button_long_release', 'turn_on'): {'command': 'on_long_release'}}), 'c5d318860f6fc9e29cb0020bda482433': ('54:ef:44:10:00:5a:ab:84', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}}), 'df839f645e8b5ac91398914d1b05a214': ('00:15:8d:00:08:ce:48:74', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}}), '14b2555892d5be15776eee1a1368ac15': ('e0:79:8d:ff:fe:e4:32:12', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}}), '203ec140778ca615a50179d6c73d3db4': ('00:15:8d:00:08:aa:50:78', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}}), '042de24aea6d4a4c790f4731dc56d4fb': ('00:15:8d:00:08:c9:41:61', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}}), 'cbf64907b6b3a51375e04ba3d788cfd0': ('00:15:8d:00:08:e0:17:08', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}}), '2118d0e22c2732d23dd99c6aada33fc1': ('94:34:69:ff:fe:60:c6:f6', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}, ('remote_button_short_press', 'turn_on'): {'command': 'on', 'cluster_id': 6, 'endpoint_id': 1}, ('remote_button_long_press', 'dim_up'): {'command': 'move_with_on_off', 'cluster_id': 8, 'endpoint_id': 1, 'params': {'move_mode': 0}}, ('remote_button_long_release', 'dim_up'): {'command': 'stop_with_on_off', 'cluster_id': 8, 'endpoint_id': 1}, ('remote_button_short_press', 'turn_off'): {'command': 'off', 'cluster_id': 6, 'endpoint_id': 1}, ('remote_button_long_press', 'dim_down'): {'command': 'move', 'cluster_id': 8, 'endpoint_id': 1, 'params': {'move_mode': 1}}, ('remote_button_long_release', 'dim_down'): {'command': 'stop', 'cluster_id': 8, 'endpoint_id': 1}}), 'd894bc999a1f5751e5a25cf3de3f6a73': ('94:34:69:ff:fe:3a:f7:3a', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}, ('remote_button_short_press', 'turn_on'): {'command': 'on', 'cluster_id': 6, 'endpoint_id': 1}, ('remote_button_long_press', 'dim_up'): {'command': 'move_with_on_off', 'cluster_id': 8, 'endpoint_id': 1, 'params': {'move_mode': 0}}, ('remote_button_long_release', 'dim_up'): {'command': 'stop_with_on_off', 'cluster_id': 8, 'endpoint_id': 1}, ('remote_button_short_press', 'turn_off'): {'command': 'off', 'cluster_id': 6, 'endpoint_id': 1}, ('remote_button_long_press', 'dim_down'): {'command': 'move', 'cluster_id': 8, 'endpoint_id': 1, 'params': {'move_mode': 1}}, ('remote_button_long_release', 'dim_down'): {'command': 'stop', 'cluster_id': 8, 'endpoint_id': 1}}), 'd039a594e10ba1a4365191b476c2770d': ('00:15:8d:00:08:93:8e:bc', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}}), 'f7cb06c87cdf8cc9d7efc1878d623eb4': ('54:ef:44:10:00:72:a1:e0', {('device_offline', 'device_offline'): {'device_event_type': 'device_offline'}})}
2024-01-12 15:37:26.484 DEBUG (Thread-292) [aiosqlite] executing <function aiosqlite_connect.<locals>.<lambda> at 0x7f079292ff60>
2024-01-12 15:37:26.484 DEBUG (Thread-292) [aiosqlite] operation <function aiosqlite_connect.<locals>.<lambda> at 0x7f079292ff60> completed
2024-01-12 15:37:26.485 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA integrity_check', [])
2024-01-12 15:37:26.488 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA integrity_check', []) completed
2024-01-12 15:37:26.489 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchall of sqlite3.Cursor object at 0x7f07a76cf5c0>)
2024-01-12 15:37:26.489 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchall of sqlite3.Cursor object at 0x7f07a76cf5c0>) completed
2024-01-12 15:37:26.490 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>)
2024-01-12 15:37:26.490 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>) completed
2024-01-12 15:37:26.490 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f079292f920>)
2024-01-12 15:37:26.491 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f079292f920>) completed
2024-01-12 15:37:26.491 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA journal_mode = WAL', [])
2024-01-12 15:37:26.491 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA journal_mode = WAL', []) completed
2024-01-12 15:37:26.492 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA synchronous = normal', [])
2024-01-12 15:37:26.492 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA synchronous = normal', []) completed
2024-01-12 15:37:26.493 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA temp_store = memory', [])
2024-01-12 15:37:26.493 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA temp_store = memory', []) completed
2024-01-12 15:37:26.494 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f07a43196c0>)
2024-01-12 15:37:26.494 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f07a43196c0>) completed
2024-01-12 15:37:26.494 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA foreign_keys = ON', [])
2024-01-12 15:37:26.494 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA foreign_keys = ON', []) completed
2024-01-12 15:37:26.495 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, "SELECT name FROM sqlite_master WHERE type='table'", [])
2024-01-12 15:37:26.496 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, "SELECT name FROM sqlite_master WHERE type='table'", []) completed
2024-01-12 15:37:26.496 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079c7039c0>, 64)
2024-01-12 15:37:26.497 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079c7039c0>, 64) completed
2024-01-12 15:37:26.498 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079c7039c0>, 64)
2024-01-12 15:37:26.498 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079c7039c0>, 64) completed
2024-01-12 15:37:26.498 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079c7039c0>)
2024-01-12 15:37:26.498 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079c7039c0>) completed
2024-01-12 15:37:26.499 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA user_version', [])
2024-01-12 15:37:26.499 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA user_version', []) completed
2024-01-12 15:37:26.499 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchone of sqlite3.Cursor object at 0x7f079c7039c0>)
2024-01-12 15:37:26.500 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchone of sqlite3.Cursor object at 0x7f079c7039c0>) completed
2024-01-12 15:37:26.500 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079c7039c0>)
2024-01-12 15:37:26.500 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079c7039c0>) completed
2024-01-12 15:37:26.500 DEBUG (MainThread) [zigpy.appdb] Current database version is v12 (table version v12)
2024-01-12 15:37:26.501 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'BEGIN TRANSACTION', [])
2024-01-12 15:37:26.501 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'BEGIN TRANSACTION', []) completed
2024-01-12 15:37:26.502 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'COMMIT', [])
2024-01-12 15:37:26.502 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'COMMIT', []) completed
2024-01-12 15:37:26.502 DEBUG (MainThread) [zigpy.appdb] Loading application state
2024-01-12 15:37:26.503 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM devices_v12', [])
2024-01-12 15:37:26.503 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM devices_v12', []) completed
2024-01-12 15:37:26.504 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64)
2024-01-12 15:37:26.504 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64) completed
2024-01-12 15:37:26.505 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64)
2024-01-12 15:37:26.506 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64) completed
2024-01-12 15:37:26.506 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>)
2024-01-12 15:37:26.506 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>) completed
2024-01-12 15:37:26.507 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM node_descriptors_v12', [])
2024-01-12 15:37:26.507 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM node_descriptors_v12', []) completed
2024-01-12 15:37:26.507 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64)
2024-01-12 15:37:26.508 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64) completed
2024-01-12 15:37:26.511 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64)
2024-01-12 15:37:26.511 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64) completed
2024-01-12 15:37:26.512 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>)
2024-01-12 15:37:26.512 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>) completed
2024-01-12 15:37:26.512 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM endpoints_v12', [])
2024-01-12 15:37:26.512 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM endpoints_v12', []) completed
2024-01-12 15:37:26.513 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64)
2024-01-12 15:37:26.514 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64) completed
2024-01-12 15:37:26.515 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64)
2024-01-12 15:37:26.515 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64) completed
2024-01-12 15:37:26.515 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>)
2024-01-12 15:37:26.515 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>) completed
2024-01-12 15:37:26.516 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM in_clusters_v12', [])
2024-01-12 15:37:26.516 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM in_clusters_v12', []) completed
2024-01-12 15:37:26.516 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64)
2024-01-12 15:37:26.518 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64) completed
2024-01-12 15:37:26.519 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64)
2024-01-12 15:37:26.519 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f07a76cf5c0>, 64) completed
2024-01-12 15:37:26.520 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>)
2024-01-12 15:37:26.520 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f07a76cf5c0>) completed
2024-01-12 15:37:26.520 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM out_clusters_v12', [])
2024-01-12 15:37:26.520 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM out_clusters_v12', []) completed
2024-01-12 15:37:26.521 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.522 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.523 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.523 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.524 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>)
2024-01-12 15:37:26.524 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>) completed
2024-01-12 15:37:26.524 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM attributes_cache_v12 WHERE attrid=4 OR attrid=5', [])
2024-01-12 15:37:26.525 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM attributes_cache_v12 WHERE attrid=4 OR attrid=5', []) completed
2024-01-12 15:37:26.525 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.526 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0000] Attribute id: 4 value: Philips
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0000] Attribute id: 5 value: ROM001
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 5 value: lumi.motion.ac02
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0x9ad6:1:0x0000] Attribute id: 4 value: AL001
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0x9ad6:1:0x0000] Attribute id: 5 value: WG001-Z01
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.527 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0000] Attribute id: 4 value: IKEA of Sweden
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0000] Attribute id: 5 value: TRADFRI on/off switch
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0000] Attribute id: 4 value: IKEA of Sweden
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0000] Attribute id: 5 value: TRADFRI on/off switch
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0x0000:1:0x0000] Attribute id: 5 value: EZSP
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0x0000:1:0x0000] Attribute id: 4 value: Silicon Labs
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.528 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0000] Attribute id: 5 value: lumi.motion.ac02
2024-01-12 15:37:26.528 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.528 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.529 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>)
2024-01-12 15:37:26.529 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>) completed
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for Silicon Labs EZSP (e0:79:8d:ff:fe:1d:16:4f)
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2}
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2}
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.tuya.ts0201.MoesTemperatureHumidtySensorWithScreen'>
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2}
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1, 2}
2024-01-12 15:37:26.529 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for Philips ROM001 (00:17:88:01:08:95:6b:27)
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'>
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:17:88:01:08:95:6b:27: <class 'zhaquirks.philips.rom001.PhilipsROM001'>
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.motion.ac02 (54:ef:44:10:00:5a:ab:84)
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.motion_ac02.LumiMotionAC02'>
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 54:ef:44:10:00:5a:ab:84: <class 'zhaquirks.xiaomi.aqara.motion_ac02.LumiMotionAC02'>
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.weather (00:15:8d:00:08:ce:48:74)
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:ce:48:74: <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for AL001 WG001-Z01 (e0:79:8d:ff:fe:e4:32:12)
2024-01-12 15:37:26.530 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2, 242}
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1, 2, 242}
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.tuya.ts0201.MoesTemperatureHumidtySensorWithScreen'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 242}
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 242}
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 242}
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {1, 2, 242}
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1, 2, 242}
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_magnet.aq2 (00:15:8d:00:08:aa:50:78)
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:aa:50:78: <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.weather (00:15:8d:00:08:c9:41:61)
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:c9:41:61: <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.weather (00:15:8d:00:08:e0:17:08)
2024-01-12 15:37:26.531 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:e0:17:08: <class 'zhaquirks.xiaomi.aqara.weather.Weather2'>
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for IKEA of Sweden TRADFRI on/off switch (94:34:69:ff:fe:60:c6:f6)
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2BtnZLL'>
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2Btn'>
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 94:34:69:ff:fe:60:c6:f6: <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2Btn'>
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for IKEA of Sweden TRADFRI on/off switch (94:34:69:ff:fe:3a:f7:3a)
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2BtnZLL'>
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2Btn'>
2024-01-12 15:37:26.532 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 94:34:69:ff:fe:3a:f7:3a: <class 'zhaquirks.ikea.twobtnremote.IkeaTradfriRemote2Btn'>
2024-01-12 15:37:26.533 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_magnet.aq2 (00:15:8d:00:08:93:8e:bc)
2024-01-12 15:37:26.533 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'>
2024-01-12 15:37:26.533 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:08:93:8e:bc: <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'>
2024-01-12 15:37:26.533 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.motion.ac02 (54:ef:44:10:00:72:a1:e0)
2024-01-12 15:37:26.533 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.motion_ac02.LumiMotionAC02'>
2024-01-12 15:37:26.533 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 54:ef:44:10:00:72:a1:e0: <class 'zhaquirks.xiaomi.aqara.motion_ac02.LumiMotionAC02'>
2024-01-12 15:37:26.533 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM attributes_cache_v12', [])
2024-01-12 15:37:26.533 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM attributes_cache_v12', []) completed
2024-01-12 15:37:26.534 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.538 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0000] Attribute id: 4 value: Philips
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0000] Attribute id: 5 value: ROM001
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0001] Attribute id: 32 value: 29
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0x80b9:1:0x0001] Attribute id: 33 value: 200
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 1 value: 6
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 5 value: lumi.motion.ac02
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0500] Attribute id: 1 value: 13
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0500] Attribute id: 16 value: e0:79:8d:ff:fe:1d:16:4f
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0001] Attribute id: 49 value: 11
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0001] Attribute id: 51 value: 1
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0400] Attribute id: 0 value: 15052.49978319906
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 258 value: 5
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 268 value: 2
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 338 value: 0
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 274 value: 65578
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0406] Attribute id: 0 value: 0
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0500] Attribute id: 0 value: 0
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0xfcc0] Attribute id: 247 value: b'\x01!\xb8\x0b\x03(\x12\x04!\x00\x00\x05!\x01\x00\x08!\x06\x01\n!\xd6\x9a\x0c \x01\x13 \x00\x14 \x00d\x10\x00e! \x00i \x05j \x02k \x00'
2024-01-12 15:37:26.539 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0001] Attribute id: 32 value: 30.0
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0001] Attribute id: 33 value: 129
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0000] Attribute id: 65281 value: b'\x01!\xa9\x0b\x04!\xa8C\x05!\x0b\x00\x06$\x01\x00\x00\x00\x00d)\xf8\x05e!{\x10f+\xac\x93\x01\x00\n!\xd6\x9a'
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0001] Attribute id: 32 value: 29.9
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0001] Attribute id: 33 value: 118
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0402] Attribute id: 0 value: 1525
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0405] Attribute id: 0 value: 4181
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb067:1:0x0403] Attribute id: 0 value: 1032
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0x9ad6:1:0x0000] Attribute id: 4 value: AL001
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0x9ad6:1:0x0000] Attribute id: 5 value: WG001-Z01
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 65281 value: b'\x01!\x95\x0b\x03(\x10\x04!\xa8\x13\x05!;\x00\x06$\x01\x00\x00\x00\x00\n!\x00\x00d\x10\x00'
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0001] Attribute id: 32 value: 29.6
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0001] Attribute id: 33 value: 104
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0002] Attribute id: 0 value: 1600
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0000] Attribute id: 65281 value: b'\x01!w\x0b\x04!\xa8C\x05!\t\x00\x06$\x01\x00\x00\x00\x00d)\x1f\x04e!=\x13f+(\x96\x01\x00\n!\xd6\x9a'
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0001] Attribute id: 32 value: 29.4
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0001] Attribute id: 33 value: 82
2024-01-12 15:37:26.540 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0402] Attribute id: 0 value: 1055
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0405] Attribute id: 0 value: 4925
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0xb4f5:1:0x0403] Attribute id: 0 value: 1039.76
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 5 value: lumi.weather
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0000] Attribute id: 65281 value: b'\x01!\x8b\x0b\x04!\xa8C\x05!\x07\x00\x06$\x01\x00\x00\x00\x00d)\x8f\x06e!\xd6\x10f+\x1a\x95\x01\x00\n!\xd6\x9a'
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0001] Attribute id: 32 value: 29.6
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0001] Attribute id: 33 value: 96
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0402] Attribute id: 0 value: 1679
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0405] Attribute id: 0 value: 4310
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x608c:1:0x0403] Attribute id: 0 value: 1037.06
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0000] Attribute id: 4 value: IKEA of Sweden
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0000] Attribute id: 5 value: TRADFRI on/off switch
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0020] Attribute id: 0 value: 13200
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0001] Attribute id: 32 value: 26
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0001] Attribute id: 33 value: 42
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0001] Attribute id: 49 value: 10
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0x8210:1:0x0001] Attribute id: 51 value: 1
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0000] Attribute id: 4 value: IKEA of Sweden
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0000] Attribute id: 5 value: TRADFRI on/off switch
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0020] Attribute id: 0 value: 13200
2024-01-12 15:37:26.541 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0001] Attribute id: 32 value: 31
2024-01-12 15:37:26.542 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.545 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0001] Attribute id: 33 value: 200
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0001] Attribute id: 49 value: 10
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf556:1:0x0001] Attribute id: 51 value: 1
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xffb5:1:0x0500] Attribute id: 2 value: 0
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0x0000:1:0x0000] Attribute id: 5 value: EZSP
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0x0000:1:0x0000] Attribute id: 4 value: Silicon Labs
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 65281 value: b'\x01!\x9f\x0b\x03(\x0e\x04!\xa8\x13\x05!v\x00\x06$\x01\x00\x00\x00\x00\n!\xd6\x9ad\x10\x01'
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0001] Attribute id: 32 value: 29.8
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0001] Attribute id: 33 value: 111
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0002] Attribute id: 0 value: 1400
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0000] Attribute id: 4 value: LUMI
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0000] Attribute id: 5 value: lumi.motion.ac02
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0500] Attribute id: 1 value: 13
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0500] Attribute id: 16 value: e0:79:8d:ff:fe:1d:16:4f
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0001] Attribute id: 49 value: 11
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0001] Attribute id: 51 value: 1
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0400] Attribute id: 0 value: 15315.789170422551
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 258 value: 5
2024-01-12 15:37:26.546 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 268 value: 2
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 338 value: 0
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 247 value: b'\x01!\xa0\x0b\x03(\x0c\x04!\x00\x00\x05!\x01\x00\x08!\x06\x01\n!\xd6\x9a\x0c \x01\x13 \x00\x14 \x00d\x10\x00e!"\x00i \x05j \x02k \x00'
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0001] Attribute id: 32 value: 29.8
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0001] Attribute id: 33 value: 111
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0500] Attribute id: 2 value: 0
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0xfcc0] Attribute id: 274 value: 65536
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0xf6d6:1:0x0406] Attribute id: 0 value: 0
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0x8554:1:0x0000] Attribute id: 1 value: 3
2024-01-12 15:37:26.547 DEBUG (MainThread) [zigpy.appdb] [0x7f8e:1:0x0000] Attribute id: 1 value: 3
2024-01-12 15:37:26.547 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.547 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.547 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>)
2024-01-12 15:37:26.547 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>) completed
2024-01-12 15:37:26.548 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM unsupported_attributes_v12', [])
2024-01-12 15:37:26.548 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM unsupported_attributes_v12', []) completed
2024-01-12 15:37:26.548 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.548 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.549 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.549 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.549 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>)
2024-01-12 15:37:26.549 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>) completed
2024-01-12 15:37:26.549 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM groups_v12', [])
2024-01-12 15:37:26.549 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM groups_v12', []) completed
2024-01-12 15:37:26.550 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.550 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.551 DEBUG (MainThread) [zigpy.group] Adding group: 21973, No name group 0x55D5
2024-01-12 15:37:26.551 DEBUG (MainThread) [zigpy.group] Adding group: 0, Default Lightlink Group
2024-01-12 15:37:26.551 DEBUG (MainThread) [zigpy.group] Adding group: 33238, No name group 0x81D6
2024-01-12 15:37:26.551 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.551 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.551 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>)
2024-01-12 15:37:26.551 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>) completed
2024-01-12 15:37:26.552 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM group_members_v12', [])
2024-01-12 15:37:26.552 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM group_members_v12', []) completed
2024-01-12 15:37:26.552 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.553 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.553 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64)
2024-01-12 15:37:26.553 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f079d90e740>, 64) completed
2024-01-12 15:37:26.553 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>)
2024-01-12 15:37:26.553 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f079d90e740>) completed
2024-01-12 15:37:26.554 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM relays_v12', [])
2024-01-12 15:37:26.554 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM relays_v12', []) completed
2024-01-12 15:37:26.554 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64)
2024-01-12 15:37:26.555 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64) completed
2024-01-12 15:37:26.555 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64)
2024-01-12 15:37:26.555 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64) completed
2024-01-12 15:37:26.556 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f0792983b40>)
2024-01-12 15:37:26.556 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f0792983b40>) completed
2024-01-12 15:37:26.556 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM neighbors_v12', [])
2024-01-12 15:37:26.556 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM neighbors_v12', []) completed
2024-01-12 15:37:26.557 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64)
2024-01-12 15:37:26.558 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64) completed
2024-01-12 15:37:26.559 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64)
2024-01-12 15:37:26.559 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64) completed
2024-01-12 15:37:26.560 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f0792983b40>)
2024-01-12 15:37:26.560 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f0792983b40>) completed
2024-01-12 15:37:26.560 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM routes_v12', [])
2024-01-12 15:37:26.560 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM routes_v12', []) completed
2024-01-12 15:37:26.561 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64)
2024-01-12 15:37:26.561 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64) completed
2024-01-12 15:37:26.562 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64)
2024-01-12 15:37:26.562 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64) completed
2024-01-12 15:37:26.562 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f0792983b40>)
2024-01-12 15:37:26.562 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f0792983b40>) completed
2024-01-12 15:37:26.563 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM network_backups_v12 ORDER BY id', [])
2024-01-12 15:37:26.563 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'SELECT * FROM network_backups_v12 ORDER BY id', []) completed
2024-01-12 15:37:26.564 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64)
2024-01-12 15:37:26.564 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64) completed
2024-01-12 15:37:26.565 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64)
2024-01-12 15:37:26.565 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method fetchmany of sqlite3.Cursor object at 0x7f0792983b40>, 64) completed
2024-01-12 15:37:26.565 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f0792983b40>)
2024-01-12 15:37:26.565 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Cursor object at 0x7f0792983b40>) completed
2024-01-12 15:37:26.566 DEBUG (MainThread) [zigpy.backups] Adding a new backup NetworkBackup(version=1, backup_time=datetime.datetime(2023, 12, 6, 2, 3, 20, 968712, tzinfo=datetime.timezone.utc), network_info=NetworkInfo(extended_pan_id=3f:73:26:41:1b:59:32:5f, pan_id=0xC280, nwk_update_id=0, nwk_manager_id=0x0000, channel=15, channel_mask=<Channels.ALL_CHANNELS: 134215680>, security_level=5, network_key=Key(key=73:0b:6d:b6:a1:7c:7c:94:cd:ea:9d:cb:d8:d3:97:e0, tx_counter=2734028, rx_counter=0, seq=0, partner_ieee=ff:ff:ff:ff:ff:ff:ff:ff), tc_link_key=Key(key=5a:69:67:42:65:65:41:6c:6c:69:61:6e:63:65:30:39, tx_counter=28672, rx_counter=0, seq=0, partner_ieee=e0:79:8d:ff:fe:1d:16:4f), key_table=[], children=[], nwk_addresses={}, stack_specific={'ezsp': {'hashed_tclk': '795da17ed0c8e1f62dee3951869e5e57'}}, metadata={'ezsp': {'manufacturer': '', 'board': '', 'version': '7.3.1.0 build 0', 'stack_version': 12, 'can_burn_userdata_custom_eui64': False, 'can_rewrite_custom_eui64': True}}, source='bellows@0.36.8'), node_info=NodeInfo(nwk=0x0000, ieee=e0:79:8d:ff:fe:1d:16:4f, logical_type=<LogicalType.Coordinator: 0>, model=None, manufacturer=None, version=None))
2024-01-12 15:37:26.566 DEBUG (MainThread) [zigpy.backups] Adding a new backup NetworkBackup(version=1, backup_time=datetime.datetime(2024, 1, 12, 11, 3, 50, 472966, tzinfo=datetime.timezone.utc), network_info=NetworkInfo(extended_pan_id=3f:73:26:41:1b:59:32:5f, pan_id=0xC280, nwk_update_id=0, nwk_manager_id=0x0000, channel=15, channel_mask=<Channels.ALL_CHANNELS: 134215680>, security_level=5, network_key=Key(key=73:0b:6d:b6:a1:7c:7c:94:cd:ea:9d:cb:d8:d3:97:e0, tx_counter=3072002, rx_counter=0, seq=0, partner_ieee=ff:ff:ff:ff:ff:ff:ff:ff), tc_link_key=Key(key=5a:69:67:42:65:65:41:6c:6c:69:61:6e:63:65:30:39, tx_counter=0, rx_counter=0, seq=0, partner_ieee=e0:79:8d:ff:fe:1d:16:4f), key_table=[], children=[], nwk_addresses={}, stack_specific={'ezsp': {'hashed_tclk': '795da17ed0c8e1f62dee3951869e5e57'}}, metadata={'ezsp': {'stack_version': 13, 'can_burn_userdata_custom_eui64': False, 'can_rewrite_custom_eui64': True}}, source='bellows@0.37.6'), node_info=NodeInfo(nwk=0x0000, ieee=e0:79:8d:ff:fe:1d:16:4f, logical_type=<LogicalType.Coordinator: 0>, model=None, manufacturer=None, version='7.4.0.0 build 0'))
2024-01-12 15:37:26.566 DEBUG (MainThread) [zigpy.serial] Opening a serial connection to 'socket://core-silabs-multiprotocol:9999' (57600 baudrate)
2024-01-12 15:37:26.568 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f0792a793a0>)
2024-01-12 15:37:26.568 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f0792a793a0>) completed
2024-01-12 15:37:26.568 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA wal_checkpoint;', [])
2024-01-12 15:37:26.569 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f07ee88dc60>, 'PRAGMA wal_checkpoint;', []) completed
2024-01-12 15:37:26.569 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f07a45865c0>)
2024-01-12 15:37:26.569 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<function PersistingListener._set_isolation_level.<locals>.<lambda> at 0x7f07a45865c0>) completed
2024-01-12 15:37:26.569 DEBUG (Thread-292) [aiosqlite] executing functools.partial(<built-in method close of sqlite3.Connection object at 0x7f07ee88dc60>)
2024-01-12 15:37:26.571 DEBUG (Thread-292) [aiosqlite] operation functools.partial(<built-in method close of sqlite3.Connection object at 0x7f07ee88dc60>) completed

puddly commented 9 months ago

Thanks! What about the addon logs?

meramsey commented 9 months ago

Same issue latest Home assistant + plugin core_silabs_multiprotocol_2024-01-12T14-29-57.419Z.log config_entry-zha-9e2af4d4a8146217d09457d3397ad39e.json.txt

Mostly third reality stuff and not using any thread/matter devices currently but planning to soon

puddly commented 9 months ago

Looks like otbr-agent is crashing:

otbr-agent[301]: 00:44:31.900 [W] P-RadioSpinel-: Handle transmit done failed: Parse
otbr-agent: ../../third_party/openthread/repo/src/core/mac/sub_mac.cpp:624: void ot::Mac::SubMac::HandleTransmitDone(ot::Mac::TxFrame&, ot::Mac::RxFrame*, ot::Error): Assertion `false' failed.

Specifically, HandleTransmitDone is unable to parse the data coming in from the radio. What's likely happening is that the radio firmware crashes and resets but a message from the radio is cut off in the middle.

bambi14 commented 9 months ago

I rolled back the Multiprotocol addon update back to 2.4.2 where is has been known to be stable in my environment. I have about 60 Zigbee devices and 3 thread bulbs. All were working fine prior to 2.4.3.

tieskuh commented 9 months ago

Thanks! What about the addon logs?

otbr-agent[301]: 01:42:19.310 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:20.329 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:20.560 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:21.398 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:21.657 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:22.361 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:24.371 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:26.353 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:28.354 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:30.354 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:32.343 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:33.874 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:34.382 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:36.373 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:38.382 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:40.340 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
otbr-agent[301]: 01:42:40.579 [W] P-RadioSpinel-: Handle transmit done failed: Parse
otbr-agent: ../../third_party/openthread/repo/src/core/mac/sub_mac.cpp:624: void ot::Mac::SubMac::HandleTransmitDone(ot::Mac::TxFrame&, ot::Mac::RxFrame*, ot::Error): Assertion `false' failed.
otbr-agent[301]: 01:42:40.579 [C] Platform------: ------------------ BEGINNING OF CRASH -------------
otbr-agent[301]: 01:42:40.579 [C] Platform------: *** FATAL ERROR: Caught signal: 6 (Aborted)
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 0: /usr/sbin/otbr-agent(+0x20088c) [0x564dac69c88c]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 1: /usr/sbin/otbr-agent(+0x2009b3) [0x564dac69c9b3]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 2: /lib/x86_64-linux-gnu/libpthread.so.0(+0x13140) [0x7f99641d7140]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 3: /lib/x86_64-linux-gnu/libc.so.6 gsignal+0x141 [0x63e3fce1]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 4: /lib/x86_64-linux-gnu/libc.so.6 abort+0x123 [0x63e29537]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 5: /lib/x86_64-linux-gnu/libc.so.6(+0x2240f) [0x7f9963e2940f]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 6: /lib/x86_64-linux-gnu/libc.so.6(+0x31662) [0x7f9963e38662]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 7: /usr/sbin/otbr-agent ot::Mac::SubMac::HandleTransmitDone(ot::Mac::TxFrame&, ot::Mac::RxFrame*, otError)+0xa8 [0xac6fe3c0]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 8: /usr/sbin/otbr-agent ot::Radio::Callbacks::HandleTransmitDone(ot::Mac::TxFrame&, ot::Mac::RxFrame*, otError)+0x39 [0xac7cb835]
otbr-agent[301]: 01:42:40.585 [C] Platform------: # 9: /usr/sbin/otbr-agent otPlatRadioTxDone+0x95 [0xac7cb4ff]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #10: /usr/sbin/otbr-agent ot::Spinel::RadioSpinel::TransmitDone(otRadioFrame*, otRadioFrame*, otError)+0x55 [0xac7990b3]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #11: /usr/sbin/otbr-agent ot::Spinel::RadioSpinel::ProcessRadioStateMachine()+0x7b [0xac799131]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #12: /usr/sbin/otbr-agent ot::Spinel::RadioSpinel::Process(void const*)+0xac [0xac799234]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #13: /usr/sbin/otbr-agent platformRadioProcess+0x27 [0xac69747e]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #14: /usr/sbin/otbr-agent otSysMainloopProcess+0x3a [0xac6998d1]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #15: /usr/sbin/otbr-agent otbr::Ncp::ControllerOpenThread::Process(otSysMainloopContext const&)+0x37 [0xac7a9f37]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #16: /usr/sbin/otbr-agent otbr::MainloopManager::Process(otSysMainloopContext const&)+0x83 [0xac7ae5d7]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #17: /usr/sbin/otbr-agent otbr::Application::Run()+0x1e0 [0xac64e564]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #18: /usr/sbin/otbr-agent(+0x1b3b5d) [0x564dac64fb5d]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #19: /usr/sbin/otbr-agent main+0x8f [0xac64fd4a]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #20: /lib/x86_64-linux-gnu/libc.so.6 __libc_start_main+0xea [0x63e2ad0a]
otbr-agent[301]: 01:42:40.585 [C] Platform------: #21: /usr/sbin/otbr-agent _start+0x2a [0xac64df7a]
otbr-agent[301]: 01:42:40.585 [C] Platform------: ------------------ END OF CRASH ------------------
[13:45:37] INFO: otbr-agent ended with exit code 256 (signal 6)...
OTBR_FORWARD_INGRESS  all opt    in * out wpan0  ::/0  -> ::/0  
Chain OTBR_FORWARD_INGRESS (0 references)
target     prot opt source               destination         
DROP       all      anywhere             anywhere             PKTTYPE = unicast
DROP       all      anywhere             anywhere             match-set otbr-ingress-deny-src src
ACCEPT     all      anywhere             anywhere             match-set otbr-ingress-allow-dst dst
DROP       all      anywhere             anywhere             PKTTYPE = unicast
ACCEPT     all      anywhere             anywhere            
otbr-ingress-deny-src
otbr-ingress-deny-src-swap
otbr-ingress-allow-dst
[2024-01-12T12:45:37.082830Z] Info : Endpoint socket #12: Client disconnected. 1 connections
[2024-01-12T12:45:37.082847Z] Info : Client disconnected
otbr-ingress-allow-dst-swap
OTBR_FORWARD_EGRESS  all opt    in wpan0 out *  ::/0  -> ::/0  
Chain OTBR_FORWARD_EGRESS (0 references)
target     prot opt source               destination         
ACCEPT     all      anywhere             anywhere            
[13:45:37] INFO: OTBR firewall teardown completed.
[13:45:37] WARNING: otbr-agent exited with code 134 (by signal 6).
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service otbr-agent-rest-discovery: stopping
s6-rc: info: service zigbeed: stopping
s6-rc: info: service mdns: stopping
s6-rc: info: service otbr-agent-rest-discovery successfully stopped
s6-rc: info: service otbr-agent: stopping
Default: mDNSResponder (Engineering Build) (Jan 11 2024 17:02:25) stopping
[13:45:37] INFO: zigbeed ended with exit code 256 (signal 15)...
[13:45:37] INFO: otbr-agent ended with exit code 256 (signal 15)...
[13:45:37] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service zigbeed successfully stopped
s6-rc: info: service mdns successfully stopped
[13:45:37] INFO: OTBR firewall teardown completed.
[13:45:37] WARNING: otbr-agent exited with code 143 (by signal 15).
s6-rc: info: service otbr-agent successfully stopped
s6-rc: info: service cpcd: stopping
[2024-01-12T12:45:37.202084Z] Info : Endpoint socket #12: Client disconnected. 0 connections
[2024-01-12T12:45:37.202169Z] Info : Client disconnected
[2024-01-12T12:45:37.246985Z] Info : Server core cleanup
[2024-01-12T12:45:37.247028Z] Info : Daemon exiting with status EXIT_SUCCESS
Logger buffer size = 28672, highwater mark = 3228 : 11.26%. Lost logs : 0
[13:45:37] INFO: CPC ended with exit code 0 (signal 0)...
s6-rc: info: service cpcd successfully stopped
s6-rc: info: service cpcd-config: stopping
s6-rc: info: service cpcd-config successfully stopped
s6-rc: info: service universal-silabs-flasher: stopping
s6-rc: info: service universal-silabs-flasher successfully stopped
s6-rc: info: service banner: stopping
s6-rc: info: service banner successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

tieskuh commented 9 months ago

Restarting the add-on also fixes the SkyConnect Multiprotocol integration. But after some time it will crash again.

puddly commented 9 months ago

Looks like the exact same problem as above, thanks.

Make sure you keep the watchdog enabled for the addon so that it auto-restarts.

tieskuh commented 9 months ago

Looks like the exact same problem as above, thanks.

Make sure you keep the watchdog enabled for the addon so that it auto-restarts.

Yes, I just did. I noticed it was off when I searched for the logs. Thanks.

Dale81 commented 9 months ago

The ever first version I installed was 2.4.3 (today), so I do not have any older versions in a backup. Is there any way to install an older version directly?

psysi commented 9 months ago

Same here. ~80 zigbee devices in the network. RPi 4, SkyConnect stick. Stable until 2.4.3 update today. Running ZHA.

szimszon commented 9 months ago

Same here :(

Swerfer commented 9 months ago

I also have this issue. Crashed 2 times in the middle of the night. ZHA in combination with Skyconnect. I now have the watchdog running and hope it will restart at the next crash so my Zigbee network will not be broken for hours...

TNTLarsn commented 9 months ago

+1

Logs maybe related:

Logger: bellows.uart
Source: runner.py:188
First occurred: 17:03:48 (1 occurrences)
Last logged: 17:03:48

Lost serial connection: ConnectionResetError('Remote server closed connection')

and

Logger: bellows.ezsp
Source: runner.py:188
First occurred: 17:03:48 (1 occurrences)
Last logged: 17:03:48

NCP entered failed state. Requesting APP controller restart

Logs (partly) from Silicon Labs Multiprotocol AddOn


otbr-agent[301]: 00:00:27.571 [N] Mle-----------: RLOC16 4400 -> fffe
otbr-agent[301]: 00:00:27.576 [W] Platform------: [netif] Failed to process request#5: Operation not supported
otbr-agent[301]: 00:00:28.285 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
otbr-agent[301]: 00:00:34.785 [N] RouterTable---: Allocate router id 17
otbr-agent[301]: 00:00:34.786 [N] Mle-----------: RLOC16 fffe -> 4400
otbr-agent[301]: 00:00:34.795 [N] Mle-----------: Role detached -> leader
otbr-agent[301]: 00:00:34.802 [N] Mle-----------: Partition ID 0x2a32ebd7
otbr-agent[301]: 00:00:34.866 [W] Platform------: [netif] Failed to process request#6: File exists
otbr-agent[301]: 00:00:34.866 [W] Platform------: [netif] ADD [U] **(IPv6 address hidden)** failed (InvalidArgs)```

DEVIDTR commented 9 months ago

Crashed, restarted, but still crashes, so went back to previous version.

DEVIDTR commented 9 months ago

I just installed from a backup. I not aware of an addon option to install a specific version.

marcelveldt commented 9 months ago

Same here. ~80 zigbee devices in the network. RPi 4, SkyConnect stick. Stable until 2.4.3 update today. Running ZHA.

If you have 80 zigbee devices you shouldn't be running Multi protocol at all but just use an additional stick for Thread OR use 3rd party border routers such as homepod minis. Multi protocol is only suitable for smaller sized setups as the radio is shared between the 2 protocols. Next to that we do not recommend multi protocol at all at this point due to stability issues.

This issue report is actually a duplicate of an existing issue: https://github.com/home-assistant/addons/issues/3192

I would advise to only use multi protocol in test setups for now. On your production setup, use zigbee only firmware and use a dedicated extra stick with thread only firmware or existing border routers from Apple or Google.

frenck commented 9 months ago

Duplicate of #3192

agners commented 9 months ago

@marcelveldt @frenck OP reports "This issue began after updating to Multiprotocol version 2.4.3. ", what makes you believe that this is a duplicate of #3192?

While I agree, such a large setup is much better served with separate radio (see also this information page about why that is), I think from a debugging perspective it might be better to collect regression reports separately from the original crashes.

szimszon commented 9 months ago

Also reverting back to Multiprotocol version 2.4.2 fixed the problem for me. I have only 17 zigbee device. Some light switch, smart plug and temp. sensors...

Stephan-4711 commented 9 months ago

I'm facing the same issue. WIth sky connect stick

Swerfer commented 9 months ago

Glad this topic is reopened. Especially because before the update there was no issue and after the update there is, regardless of if we should or shouldn't use the integration for whatever reason.

Guardempire commented 9 months ago

I have the same problem, ZHA is in initialization status and nothing works anymore... unti a complete reboot. I have the Skyconnect stick and it runs in multiprotocol mode, although I don't have any Thread devices yet. But exactly this mode was the reason to buy it and switch from Sonoff... Because it was supposed to support everything and now the solution is to let it run on Zigbee only and use something else for Thread? It worked completely error-free and without failures until a certain update.

agners commented 9 months ago

Unfortunately, previous versions also did not work for all users error free :cry: . Especially folks which were using the Thread network as well. So we do have to continue development, and update to newer version.

We've recently updated to Silicon Labs latest version based on Gecko SDK 4.4.0. Unfortunately, as many of you observe, this seems to have negative effect on some system.

@Guardempire (and others) Home Assistant creates a add-on specific backup by default. If previous versions do work fine for you, you can simply downgrade to that previous version and skip/ignore this update.

The multiprotocol solution has also some technical downsides. If you have two sticks anyways, I'd consider using them to form separate networks (as linked above, see this article).

We'll continue to work with Silicon Labs to get to the bottom of (all) the issues. :crossed_fingers:

szimszon commented 9 months ago

Hi @agners ,

This is the kind of communication I like. Understanding, informative, helpful and hopeful. Thank you!

Guardempire commented 9 months ago

Hey @agners, thank you for the honest and explanatory words! I really can understand your side, but for the buyer of the sticks, who has normally paid twice as much as for the Sonoff dongle, there is a certain expectation. The stick's website also points out that it is still under development, but it says "Zigbee and Thread at the same time". Perhaps more information during installation and on the website would prevent people from using it in the production environment!? I will, as I "fortunately" don't use a Thread device yet, revert to Zigbee only and hope it works then. It's always hard to explain to the wife why the light suddenly doesn't come on when she's standing in the kitchen in the dark in the morning :D

Greetings! Henry

szimszon commented 9 months ago

Maybe a disclaimer for the product: Only for development purposes and don't use it in production environment.

puddly commented 9 months ago

This issue has been fixed with the latest version of the addon.

home-assistant / addons