search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.27k stars 30.25k forks source link

ZHA unreliable and slow on boot (async_initialize: all attempts have failed) with Conbee 2 #62494

Closed dflvunoooooo closed 2 years ago

dflvunoooooo commented 2 years ago

The problem

I switched from deconz to zha four weeks ago, because one of my devices is not supported, but now I have a lot issues with zha. Lights do not properly turn on and more often turn on again, after I turned them off. The log is fludded with WARNING logs. And if I reboot Home Assistant, it takes up to 60 seconds until all devices are available again.

What version of Home Assistant Core has the issue?

2021.12.4

What was the last working version of Home Assistant Core?

No idea, had the problem since I switched from deconz.

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Zigbee Home Automation

Link to integration documentation on our website

https://www.home-assistant.io/integrations/zha/

Example YAML snippet

No response

Anything in the logs that might be useful for us?

…
2021-12-21 14:05:50 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: async_initialize: all attempts have failed: [DeliveryError('[0xf542:11:0x0008]: Message send failure'), DeliveryError('[0xf542:11:0x0008]: Message send failure'), DeliveryError('[0xf542:11:0x0008]: Message send failure'), DeliveryError('[0xf542:11:0x0008]: Message send failure')]
…
2021-12-21 14:05:55 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.wohnzimmer_eurotronic_thermostat
2021-12-21 14:05:55 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.kueche_eurotronic_thermostat
2021-12-21 14:05:55 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.bad_eurotronic_thermostat
2021-12-21 14:05:55 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.schlafzimmer_eurotronic_thermostat
2021-12-21 14:05:55 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.bad_eurotronic_thermostat
2021-12-21 14:05:55 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities light.kueche_kuelschrank_tint_ambiw
2021-12-21 14:05:55 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.bad_eurotronic_thermostat
2021-12-21 14:05:55 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities light.schlafzimmer_schreibtisch_philips_ambiw
2021-12-21 14:05:56 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities switch.schlafzimmer_schreibtisch_osram_stecker
2021-12-21 14:06:31 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0xf542:11:0x0006]: Message send failure'), DeliveryError('[0xf542:11:0x0006]: Message send failure'), DeliveryError('[0xf542:11:0x0006]: Message send failure'), DeliveryError('[0xf542:11:0x0006]: Message send failure')]
2021-12-21 14:07:33 WARNING (MainThread) [zigpy_deconz.api] No response to 'Command.aps_data_indication' command with seq id '0x02'

Additional information

Home Assistant OS is running in an VM and the conbee stick has an USB extension cable.

probot-home-assistant[bot] commented 2 years ago

Hey there @dmulcahey, @adminiuga, mind taking a look at this issue as it has been labeled with an integration (zha) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

zha documentation zha source (message by IssueLinks)

Adminiuga commented 2 years ago

That error means the device is not responding to the network request, either because it is turned off or networking problem. Nothing zha can do about it, other than logging a message

dflvunoooooo commented 2 years ago

But to what is it related, if not zha? I hadn't had this problems with deconz. And the devices are in the same setup as before the reboot and not turned off.

NickM-27 commented 2 years ago

I use ZHA with Conbee II and have no such issues. If you moved from deconz to ZHA without unpairing and repairing the devices then perhaps there is something that went haywire and is causing issues. Might be worth removing / resetting your devices and starting fresh.

If that isn't the case, might also be worth getting a USB extension cable to reduce interference, that definitely helped my setup respond faster / have better signal etc.

Adminiuga commented 2 years ago

But to what is it related, if not zha?

It is outside of zha controls. Zha is telling the ConBee to send a request to the light bulb. The request was sent (supposedly, but you didn't provide any debug logs, so just guessing) but there was no reply from the light, so zha logs a warning telling that light failed to respond. Zha cannot force the light to respond.

Make sure you firmware now updated to the latest one and use USB extension cord.

dflvunoooooo commented 2 years ago

Thanks for yuor answers!

I use ZHA with Conbee II and have no such issues. If you moved from deconz to ZHA without unpairing and repairing the devices then perhaps there is something that went haywire and is causing issues. Might be worth removing / resetting your devices and starting fresh.

If that isn't the case, might also be worth getting a USB extension cable to reduce interference, that definitely helped my setup respond faster / have better signal etc.

Ah interesting, then it is indeed something with my setup? I am not the only one with this problems community.home-assistant.io. I had to pair all devices anew with zha, with most I had to reset them to do so. Do you think it would help, if I would power up deconz again and delete all devices there?

An extension cable is already in place.

But to what is it related, if not zha?

It is outside of zha controls. Zha is telling the ConBee to send a request to the light bulb. The request was sent (supposedly, but you didn't provide any debug logs, so just guessing) but there was no reply from the light, so zha logs a warning telling that light failed to respond. Zha cannot force the light to respond.

Make sure you firmware now updated to the latest one and use USB extension cord.

The firmware of the conbee 2 is up to date and I use an extension cable. The debug log is very long. Here it is:

2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0000](dresden elektronik ConBee II) restored as 'available', last seen: 1:35:06 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xDFE0](Philips RWL021) restored as 'available', last seen: 4:45:22 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xE8C7](MLI ZBT-ExtendedColor) restored as 'available', last seen: 0:00:55 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x39BB](innr RB 185 C) restored as 'available', last seen: 0:03:24 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x000A](Philips LCA001) restored as 'available', last seen: 0:03:24 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x3A11](LUMI lumi.sensor_motion.aq2) restored as 'available', last seen: 0:29:17 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'ElectricalMeasurement' using ['electrical_measurement']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'ElectricalMeasurementApparentPower' using ['electrical_measurement']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'ElectricalMeasurementRMSCurrent' using ['electrical_measurement']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'ElectricalMeasurementRMSVoltage' using ['electrical_measurement']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'SmartEnergyMetering' using ['smartenergy_metering']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'SmartEnergySummation' using ['smartenergy_metering']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x1F84](_TZ3000_g5xawfcq TS0121) restored as 'available', last seen: 0:00:47 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x612D](Philips LTW010) restored as 'available', last seen: 0:00:43 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xBF28](IKEA of Sweden TRADFRI on/off switch) restored as 'available', last seen: 3:44:33 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'climate' component -> 'Thermostat' using ['thermostat']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'ThermostatHVACAction' using ['thermostat']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xCF13](Eurotronic SPZB0001) restored as 'available', last seen: 0:03:09 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'climate' component -> 'Thermostat' using ['thermostat']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'ThermostatHVACAction' using ['thermostat']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x2F88](Eurotronic SPZB0001) restored as 'available', last seen: 0:01:00 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x5C6C](Philips LTW010) restored as 'available', last seen: 0:01:35 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xFA43](Philips LTW010) restored as 'available', last seen: 0:01:04 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xF031](IKEA of Sweden TRADFRI on/off switch) restored as 'available', last seen: 0:15:37 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x56AF](OSRAM Plug 01) restored as 'available', last seen: 0:04:19 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x8F47](LUMI lumi.sensor_motion) restored as 'available', last seen: 0:10:18 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x4313](IKEA of Sweden TRADFRI on/off switch) restored as 'available', last seen: 3:16:47 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x2C23](MLI ZBT-ColorTemperature) restored as 'available', last seen: 0:03:08 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x96EE](IKEA of Sweden TRADFRI on/off switch) restored as 'available', last seen: 4:42:35 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x2F2F](LUMI lumi.sensor_motion.aq2) restored as 'available', last seen: 0:14:05 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x775E](IKEA of Sweden TRADFRI on/off switch) restored as 'unavailable', last seen: 21:24:14 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'climate' component -> 'Thermostat' using ['thermostat']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'ThermostatHVACAction' using ['thermostat']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x3782](Eurotronic SPZB0001) restored as 'available', last seen: 0:08:17 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x1189](LUMI lumi.sensor_magnet.aq2) restored as 'available', last seen: 0:31:40 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x4A6B](LUMI lumi.magnet.acn001) restored as 'available', last seen: 0:08:13 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x428F](LUMI lumi.sensor_magnet.aq2) restored as 'available', last seen: 0:22:32 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xA0B7](_TZ2000_hjsgdkfl TS0201) restored as 'available', last seen: 0:02:03 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x9E2C](_TZ2000_hjsgdkfl TS0201) restored as 'available', last seen: 0:06:59 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xBC53](LUMI lumi.sensor_magnet.aq2) restored as 'available', last seen: 0:35:48 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x5A0D](LUMI lumi.magnet.acn001) restored as 'available', last seen: 0:19:30 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xF542](Philips LWB010) restored as 'unavailable', last seen: 13 days, 21:01:38 ago, consider_unavailable_time: 7200 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'climate' component -> 'Thermostat' using ['thermostat']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'ThermostatHVACAction' using ['thermostat']
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xFB32](Eurotronic SPZB0001) restored as 'available', last seen: 0:01:38 ago, consider_unavailable_time: 21600 seconds
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0xFFF0:0xfff0 has less than 2 members - skipping entity discovery
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] Loading battery powered devices
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xDFE0](RWL021): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:ZDO](RWL021): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3A11](lumi.sensor_motion.aq2): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:ZDO](lumi.sensor_motion.aq2): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0008]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0005]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0005]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x000f]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x000f]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0xfc00]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0xfc00]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0406]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0406]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0500]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0500]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0400]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0400]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:1:0x0005]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x000f]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0xfc00]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDFE0:2:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0406]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0500]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0400]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3A11:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xDFE0](RWL021): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xDFE0](RWL021): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3A11](lumi.sensor_motion.aq2): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3A11](lumi.sensor_motion.aq2): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBF28](TRADFRI on/off switch): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:ZDO](TRADFRI on/off switch): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xCF13](SPZB0001): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:ZDO](SPZB0001): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x1000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x1000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0020]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0020]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0102]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0102]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0008]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0020]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0102]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBF28:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBF28](TRADFRI on/off switch): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBF28](TRADFRI on/off switch): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xCF13](SPZB0001): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xCF13](SPZB0001): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F88](SPZB0001): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:ZDO](SPZB0001): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xF031](TRADFRI on/off switch): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:ZDO](TRADFRI on/off switch): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0201]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0201]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x1000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x1000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0020]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0020]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0102]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0102]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0008]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0201]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0020]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0102]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF031:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F88](SPZB0001): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F88](SPZB0001): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xF031](TRADFRI on/off switch): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xF031](TRADFRI on/off switch): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x8F47](lumi.sensor_motion): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:ZDO](lumi.sensor_motion): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x4313](TRADFRI on/off switch): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:ZDO](TRADFRI on/off switch): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0406]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0406]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0500]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0500]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0005]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0005]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x1000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x1000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0020]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0020]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0102]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0102]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0008]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0406]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0500]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x8F47:1:0x0005]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0020]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0102]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4313:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x8F47](lumi.sensor_motion): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x8F47](lumi.sensor_motion): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x4313](TRADFRI on/off switch): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x4313](TRADFRI on/off switch): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x96EE](TRADFRI on/off switch): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:ZDO](TRADFRI on/off switch): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F2F](lumi.sensor_motion.aq2): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:ZDO](lumi.sensor_motion.aq2): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x1000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x1000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0020]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0020]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0102]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0102]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0008]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0406]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0406]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0500]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0500]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0400]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0400]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0020]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0102]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x96EE:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0406]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0500]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0400]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x96EE](TRADFRI on/off switch): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x96EE](TRADFRI on/off switch): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F2F](lumi.sensor_motion.aq2): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F2F](lumi.sensor_motion.aq2): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x775E](TRADFRI on/off switch): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:ZDO](TRADFRI on/off switch): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3782](SPZB0001): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:ZDO](SPZB0001): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x1000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x1000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0020]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0020]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0102]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0102]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0008]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0020]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0102]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x775E:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x775E](TRADFRI on/off switch): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x775E](TRADFRI on/off switch): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3782](SPZB0001): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x3782](SPZB0001): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1189](lumi.sensor_magnet.aq2): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:ZDO](lumi.sensor_magnet.aq2): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x4A6B](lumi.magnet.acn001): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:ZDO](lumi.magnet.acn001): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0500]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0500]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0xfcc0]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0xfcc0]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1189:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0500]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0xfcc0]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x4A6B:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1189](lumi.sensor_magnet.aq2): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1189](lumi.sensor_magnet.aq2): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x4A6B](lumi.magnet.acn001): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x4A6B](lumi.magnet.acn001): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x428F](lumi.sensor_magnet.aq2): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:ZDO](lumi.sensor_magnet.aq2): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xA0B7](TS0201): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:ZDO](TS0201): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0405]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0405]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0402]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0402]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x428F:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0405]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0402]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0B7:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x428F](lumi.sensor_magnet.aq2): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x428F](lumi.sensor_magnet.aq2): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xA0B7](TS0201): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xA0B7](TS0201): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9E2C](TS0201): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:ZDO](TS0201): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBC53](lumi.sensor_magnet.aq2): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:ZDO](lumi.sensor_magnet.aq2): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0405]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0405]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0402]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0402]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0006]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0405]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0402]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x9E2C:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBC53:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9E2C](TS0201): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x9E2C](TS0201): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBC53](lumi.sensor_magnet.aq2): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBC53](lumi.sensor_magnet.aq2): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x5A0D](lumi.magnet.acn001): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:ZDO](lumi.magnet.acn001): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xFB32](SPZB0001): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:ZDO](SPZB0001): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0500]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0500]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0xfcc0]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0xfcc0]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0001]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0001]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0000]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0019]: initializing channel: from_cache: True
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0500]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0xfcc0]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5A0D:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0001]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x5A0D](lumi.magnet.acn001): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x5A0D](lumi.magnet.acn001): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xFB32](SPZB0001): power source: Battery or Unknown
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xFB32](SPZB0001): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] Loading mains powered devices
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](ConBee II): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:ZDO](ConBee II): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xE8C7](ZBT-ExtendedColor): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:ZDO](ZBT-ExtendedColor): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:1:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0300]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](ConBee II): power source: Mains
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](ConBee II): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x39BB](RB 185 C): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:ZDO](RB 185 C): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0300]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:2:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:2:0x1000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:2:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x1000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0300]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0300]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xE8C7](ZBT-ExtendedColor): power source: Mains
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xE8C7](ZBT-ExtendedColor): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x000A](LCA001): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:ZDO](LCA001): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0300]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0300]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x1000]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0019]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0008]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0006]: finished channel initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0300]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x000A](LCA001): power source: Mains
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x000A](LCA001): completed initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1F84](TS0121): started initialization
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:ZDO](TS0121): 'async_initialize' stage succeeded
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0b04]: initializing channel: from_cache: False
2021-12-22 16:15:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0702]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0006]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0019]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0702]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0b04]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0b04]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0702]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1F84](TS0121): power source: Mains
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x1F84](TS0121): completed initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x612D](LTW010): started initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:ZDO](LTW010): 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0300]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0006]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x1000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0019]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0300]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0008]: received attribute: 0 update with value: 224
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0008]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0300]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x612D](LTW010): power source: Mains
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x612D](LTW010): completed initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x5C6C](LTW010): started initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:ZDO](LTW010): 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0300]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0006]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x1000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0019]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0300]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0008]: received attribute: 0 update with value: 224
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0008]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0300]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x5C6C](LTW010): power source: Mains
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x5C6C](LTW010): completed initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xFA43](LTW010): started initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:ZDO](LTW010): 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0300]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0006]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x1000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0019]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0300]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0008]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0300]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xFA43](LTW010): power source: Mains
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xFA43](LTW010): completed initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x56AF](Plug 01): started initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:ZDO](Plug 01): 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x1000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0019]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0006]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x56AF](Plug 01): power source: Mains
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x56AF](Plug 01): completed initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2C23](ZBT-ColorTemperature): started initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:ZDO](ZBT-ColorTemperature): 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0300]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0006]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x1000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0019]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0008]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0300]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0300]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2C23](ZBT-ColorTemperature): power source: Mains
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2C23](ZBT-ColorTemperature): completed initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xF542](LWB010): started initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:ZDO](LWB010): 'async_initialize' stage succeeded
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x1000]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x1000]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0019]: initializing channel: from_cache: False
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0019]: finished channel initialization
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: failed to get attributes '['current_level']' on 'level' cluster: [0xf542:11:0x0008]: Message send failure
2021-12-22 16:15:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: async_initialize: retryable request #1 failed: [0xf542:11:0x0008]: Message send failure. Retrying in 1.1s
2021-12-22 16:15:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: failed to get attributes '['current_level']' on 'level' cluster: [0xf542:11:0x0008]: Message send failure
2021-12-22 16:15:45 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: async_initialize: retryable request #2 failed: [0xf542:11:0x0008]: Message send failure. Retrying in 0.8s
2021-12-22 16:15:46 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:46 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: failed to get attributes '['current_level']' on 'level' cluster: [0xf542:11:0x0008]: Message send failure
2021-12-22 16:15:46 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: async_initialize: retryable request #3 failed: [0xf542:11:0x0008]: Message send failure. Retrying in 3.1s
2021-12-22 16:15:46 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: Attribute report 'ThermostatCluster'[unoccupied_heating_setpoint] = 1600
2021-12-22 16:15:48 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0300]: failed to get attributes '['color_loop_active', 'current_x', 'current_y', 'color_temperature']' on 'light_color' cluster:
2021-12-22 16:15:48 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0300]: async_initialize: retryable request #1 failed: . Retrying in 1.1s
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: initializing channel: from_cache: False
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: failed to get attributes '['current_level']' on 'level' cluster: [0xf542:11:0x0008]: Message send failure
2021-12-22 16:15:49 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: async_initialize: all attempts have failed: [DeliveryError('[0xf542:11:0x0008]: Message send failure'), DeliveryError('[0xf542:11:0x0008]: Message send failure'), DeliveryError('[0xf542:11:0x0008]: Message send failure'), DeliveryError('[0xf542:11:0x0008]: Message send failure')]
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0300]: initializing channel: from_cache: False
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0300]: finished channel initialization
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0300]: 'async_initialize' stage succeeded
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x39BB](RB 185 C): power source: Mains
2021-12-22 16:15:49 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x39BB](RB 185 C): completed initialization
2021-12-22 16:15:51 WARNING (MainThread) [homeassistant.components.media_player] Setup of media_player platform onkyo is taking over 10 seconds.
2021-12-22 16:15:54 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0xf542:11:0x0006]: Message send failure
2021-12-22 16:15:54 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: async_initialize: retryable request #1 failed: [0xf542:11:0x0006]: Message send failure. Retrying in 1.1s
2021-12-22 16:15:55 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: initializing channel: from_cache: False
2021-12-22 16:16:00 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.wohnzimmer_eurotronic_thermostat
2021-12-22 16:16:00 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.kueche_eurotronic_thermostat
2021-12-22 16:16:00 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.bad_eurotronic_thermostat
2021-12-22 16:16:00 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.schlafzimmer_eurotronic_thermostat
2021-12-22 16:16:01 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities climate.bad_eurotronic_thermostat
2021-12-22 16:16:01 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities light.kueche_kuelschrank_tint_ambiw
2021-12-22 16:16:01 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities light.schlafzimmer_schreibtisch_philips_ambiw
2021-12-22 16:16:01 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities switch.schlafzimmer_schreibtisch_osram_stecker
2021-12-22 16:16:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: Attribute report 'ThermostatCluster'[system_mode] = 4
2021-12-22 16:16:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: Attribute report 'ThermostatCluster'[host_flags] = 1
2021-12-22 16:16:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0xf542:11:0x0006]: Message send failure
2021-12-22 16:16:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: async_initialize: retryable request #2 failed: [0xf542:11:0x0006]: Message send failure. Retrying in 1.2s
2021-12-22 16:16:07 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: initializing channel: from_cache: False
2021-12-22 16:16:09 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: Attribute report 'ThermostatCluster'[occupied_heating_setpoint] = 1000
2021-12-22 16:16:17 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0xf542:11:0x0006]: Message send failure
2021-12-22 16:16:17 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: async_initialize: retryable request #3 failed: [0xf542:11:0x0006]: Message send failure. Retrying in 2.9s
2021-12-22 16:16:20 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: initializing channel: from_cache: False
2021-12-22 16:16:27 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: Attribute report 'ThermostatCluster'[errors] = 8
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: [0xf542:11:0x0006]: Message send failure
2021-12-22 16:16:30 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0xf542:11:0x0006]: Message send failure'), DeliveryError('[0xf542:11:0x0006]: Message send failure'), DeliveryError('[0xf542:11:0x0006]: Message send failure'), DeliveryError('[0xf542:11:0x0006]: Message send failure')]
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0006]: 'async_initialize' stage succeeded
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0008]: 'async_initialize' stage succeeded
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0000]: 'async_initialize' stage succeeded
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x1000]: 'async_initialize' stage succeeded
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF542:11:0x0019]: 'async_initialize' stage succeeded
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xF542](LWB010): power source: Mains
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xF542](LWB010): completed initialization
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.entity] None: polling current state
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.entity] None: polling current state
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.entity] None: polling current state
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.entity] None: polling current state
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.entity] None: polling current state
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.entity] None: polling current state
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.entity] None: polling current state
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0006]: attempting to update onoff state - from cache: False
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56AF:3:0x0006]: attempting to update onoff state - from cache: False
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE8C7:1:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x39BB:1:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x000A:11:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x612D:11:0x0008]: received attribute: 0 update with value: 224
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5C6C:11:0x0008]: received attribute: 0 update with value: 224
2021-12-22 16:16:30 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:16:31 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0008]: executed 'move_to_level_with_on_off' command with args: '(254, 10.0)' kwargs: '{}' result: [4, <Status.SUCCESS: 0>]
2021-12-22 16:16:31 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2C23:1:0x0300]: executed 'move_to_color_temp' command with args: '(349, 10.0)' kwargs: '{}' result: [10, <Status.SUCCESS: 0>]
2021-12-22 16:16:31 DEBUG (MainThread) [homeassistant.components.zha.entity] light.kueche_kuelschrank_tint_ambiw: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'move_to_color_temp': [10, <Status.SUCCESS: 0>]}
2021-12-22 16:16:31 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0201]: wrote {'system_mode': <SystemMode.HEAT: 4>} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:31 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0201]: set system to SystemMode.HEAT
2021-12-22 16:16:31 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0201]: wrote {'occupied_heating_setpoint': 2060} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:32 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F88:1:0x0201]: Attribute report 'ThermostatCluster'[local_temp] = 1735
2021-12-22 16:16:32 DEBUG (MainThread) [homeassistant.components.zha.entity] climate.bad_eurotronic_thermostat: Attribute 'local_temp' = 1735 update
2021-12-22 16:16:33 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: wrote {'system_mode': <SystemMode.HEAT: 4>} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:33 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: set system to SystemMode.HEAT
2021-12-22 16:16:33 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: wrote {'system_mode': <SystemMode.HEAT: 4>} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:33 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3782:1:0x0201]: set system to SystemMode.HEAT
2021-12-22 16:16:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: wrote {'system_mode': <SystemMode.HEAT: 4>} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: set system to SystemMode.HEAT
2021-12-22 16:16:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: wrote {'system_mode': <SystemMode.HEAT: 4>} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: set system to SystemMode.HEAT
2021-12-22 16:16:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: wrote {'system_mode': <SystemMode.HEAT: 4>} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:34 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: set system to SystemMode.HEAT
2021-12-22 16:16:35 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: wrote {'system_mode': <SystemMode.HEAT: 4>} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:35 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: set system to SystemMode.HEAT
2021-12-22 16:16:35 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: wrote {'system_mode': <SystemMode.HEAT: 4>} attrs, Status: [[WriteAttributesStatusRecord(status=<Status.SUCCESS: 0>)]]
2021-12-22 16:16:35 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFB32:1:0x0201]: set system to SystemMode.HEAT
2021-12-22 16:16:35 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: Attribute report 'ThermostatCluster'[local_temp] = 2043
2021-12-22 16:16:35 DEBUG (MainThread) [homeassistant.components.zha.entity] climate.kueche_eurotronic_thermostat: Attribute 'local_temp' = 2043 update
2021-12-22 16:16:35 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA43:11:0x0008]: received attribute: 0 update with value: 254
2021-12-22 16:16:52 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x775E](TRADFRI on/off switch): Attempting to checkin with device - missed checkins: 1
2021-12-22 16:16:53 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xF542](LWB010): Attempting to checkin with device - missed checkins: 1
2021-12-22 16:16:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: Attribute report 'ThermostatCluster'[system_mode] = 4
2021-12-22 16:16:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCF13:1:0x0201]: Attribute report 'ThermostatCluster'[host_flags] = 1
2021-12-22 16:16:59 DEBUG (MainThread) [homeassistant.components.zha.entity] climate.kueche_eurotronic_thermostat: Attribute 'system_mode' = 4 update
2021-12-22 16:16:59 DEBUG (MainThread) [homeassistant.components.zha.entity] climate.kueche_eurotronic_thermostat: Attribute 'host_flags' = 1 update
2021-12-22 16:17:00 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x1F84:1:0x0b04]: async_update
mkammes commented 2 years ago

I can confirm the same behavior and in the same scenario.

2021.12.x (I've noticed this with several of the last dot releases). Raspberry Pi4

I also moved from Nortek to Conbee II for compatibility issues (Lutron Aurora). I used deCONZ with the Conbee II at first, then repaired everything to zha.

Also using a USB extension cable for the Conbee II. Firmware is current (can't locate exact rev since deCONZ was removed).

Partial log:

2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0000](dresden elektronik ConBee II) restored as 'available', last seen: 1:52:30 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x3741](Philips LCD002) restored as 'available', last seen: 0:04:36 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xC9F1](Philips LCD002) restored as 'available', last seen: 0:04:36 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0B56](Philips LCD002) restored as 'available', last seen: 0:04:36 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xF071](Philips LCD002) restored as 'available', last seen: 0:04:29 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x7FCB](Philips LCD002) restored as 'available', last seen: 0:04:36 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xE597](Lutron Z3-1BRL) restored as 'available', last seen: 0:06:41 ago, consider_unavailable_time: 21600 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x7CB3](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'unavailable', last seen: 14:45:38 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x8F07](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'unavailable', last seen: 14:46:43 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x160B](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'unavailable', last seen: 14:43:18 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0130](ETI Zigbee CCT Downlight) restored as 'unavailable', last seen: 9:47:57 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x1209](ETI Zigbee CCT Downlight) restored as 'unavailable', last seen: 9:48:09 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x12F0](ETI Zigbee CCT Downlight) restored as 'unavailable', last seen: 9:35:52 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x1A93](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'unavailable', last seen: 1 day, 18:05:04 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xA0EA](Lutron Z3-1BRL) restored as 'available', last seen: 0:20:56 ago, consider_unavailable_time: 21600 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x641C](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'available', last seen: 0:02:51 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xB8B0](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'available', last seen: 0:01:40 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xDFF8](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'available', last seen: 0:02:51 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0D13](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'available', last seen: 0:02:51 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xD331](The Home Depot Ecosmart-ZBT-BR30-CCT-Bulb) restored as 'available', last seen: 0:02:51 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xA6CC](The Home Depot Ecosmart-ZBT-A19-CCT-Bulb) restored as 'unavailable', last seen: 3 days, 16:54:00 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x5B0B](The Home Depot Ecosmart-ZBT-A19-CCT-Bulb) restored as 'unavailable', last seen: 3 days, 16:25:08 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x004C](ETI Zigbee CCT Downlight) restored as 'unavailable', last seen: 12:57:33 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xE9E3](ETI Zigbee CCT Downlight) restored as 'unavailable', last seen: 13:29:17 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'SmartEnergyMetering' using ['smartenergy_metering']
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'SmartEnergySummation' using ['smartenergy_metering']
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x53E8](sengled E21-N1EA) restored as 'available', last seen: 0:00:51 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x9F90](Jasco Products 43100) restored as 'available', last seen: 0:01:19 ago, consider_unavailable_time: 7200 seconds
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0x0287:0x0287 has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0x00DC:0x00dc has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0x00F5:0x00f5 has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0x00EB:0x00eb has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0x00CC:0x00cc has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0x00FE:0x00fe has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0x00FF:0x00ff has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0xFFF0:0xfff0 has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0x0001:0x0001 has less than 2 members - skipping entity discovery
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event device_registry_updated[L]: action=update, device_id=31215ff214862cd6104755b7133eac93>
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=permit>
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=remove>
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=set_zigbee_cluster_attribute>
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=issue_zigbee_cluster_command>
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=issue_zigbee_group_command>
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=warning_device_squawk>
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=zha, service=warning_device_warn>
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] Loading battery powered devices
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [2943277352] Sending {"id": 5, "type": "event", "event": {"event_type": "service_registered", "data": {"domain": "zha", "service": "permit"}, "origin": "LOCAL", "time_fired": "2021-12-22T20:43:38.563304+00:00", "context": {"id": "adbd34b2432d0d05480bceccc0b2291e", "parent_id": null, "user_id": null}}}
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [2943277352] Sending {"id": 5, "type": "event", "event": {"event_type": "service_registered", "data": {"domain": "zha", "service": "remove"}, "origin": "LOCAL", "time_fired": "2021-12-22T20:43:38.563559+00:00", "context": {"id": "a6d5c1cef31fd223acde46d28c44b232", "parent_id": null, "user_id": null}}}
2021-12-22 12:43:38 INFO (SyncWorker_5) [homeassistant.loader] Loaded lock from homeassistant.components.lock
2021-12-22 12:43:38 INFO (SyncWorker_2) [homeassistant.loader] Loaded siren from homeassistant.components.siren
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [2943277352] Sending {"id": 5, "type": "event", "event": {"event_type": "service_registered", "data": {"domain": "zha", "service": "set_zigbee_cluster_attribute"}, "origin": "LOCAL", "time_fired": "2021-12-22T20:43:38.563801+00:00", "context": {"id": "43b1145c1ef73180bab14cec25c2bc25", "parent_id": null, "user_id": null}}}
2021-12-22 12:43:38 INFO (SyncWorker_0) [homeassistant.loader] Loaded alarm_control_panel from homeassistant.components.alarm_control_panel
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [2943277352] Sending {"id": 5, "type": "event", "event": {"event_type": "service_registered", "data": {"domain": "zha", "service": "issue_zigbee_cluster_command"}, "origin": "LOCAL", "time_fired": "2021-12-22T20:43:38.564079+00:00", "context": {"id": "533faed72a70626a8b1f8a47b260b062", "parent_id": null, "user_id": null}}}
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [2943277352] Sending {"id": 5, "type": "event", "event": {"event_type": "service_registered", "data": {"domain": "zha", "service": "issue_zigbee_group_command"}, "origin": "LOCAL", "time_fired": "2021-12-22T20:43:38.564316+00:00", "context": {"id": "2aa2736b4aceeb07b0a5131c81007412", "parent_id": null, "user_id": null}}}
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [2943277352] Sending {"id": 5, "type": "event", "event": {"event_type": "service_registered", "data": {"domain": "zha", "service": "warning_device_squawk"}, "origin": "LOCAL", "time_fired": "2021-12-22T20:43:38.564552+00:00", "context": {"id": "abd983ddca411b1bb33d7f6c7a9dd0e9", "parent_id": null, "user_id": null}}}
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [2943277352] Sending {"id": 5, "type": "event", "event": {"event_type": "service_registered", "data": {"domain": "zha", "service": "warning_device_warn"}, "origin": "LOCAL", "time_fired": "2021-12-22T20:43:38.564886+00:00", "context": {"id": "48e0fb1988fba24cbef95f2e01849199", "parent_id": null, "user_id": null}}}
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xE597](Z3-1BRL): started initialization
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xE597:ZDO](Z3-1BRL): 'async_initialize' stage succeeded
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xA0EA](Z3-1BRL): started initialization
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xA0EA:ZDO](Z3-1BRL): 'async_initialize' stage succeeded
2021-12-22 12:43:38 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=zha>
moridianmess commented 2 years ago

Don't know if this is the same thing, but I just did a manual migration from deconz, my set up is VirtualBox with a Conbee II. I was also getting similar very slow behavior too. If you restart HomeAssistant it was taking nearly 2 minutes to start ZHA, until I removed the deconz supervisor add-on. Now everything starts super fast, hopefully that helps someone else.

mkammes commented 2 years ago

I've done further testing and researched further - plus upgraded to a Sonoff Zigbee 3.0 Plus from a Conbee II.

The delay is still present - Zigbee devices don't become available until 6 minutes after a HA restart.

I think the issue is that ~a dozen of my smart bulbs are on hard wall switches, so if they are turned off at the switch, the zha bulbs are never seen by HA. HA continues to try and find the devices (5 times?) and I think that may be the issue here.

I tested this theory and restarted HA with all zha devices on and accessible. Sure enough, I cut the delay down to under a minute.

I will say that this same zha config with older HA versions (early 2021?) was available quicker through the UI- even if they were unreachable - than later 2021 versions.

dflvunoooooo commented 2 years ago

So, I tried a bit more. I deactivated ZHA, rebooted, restored deconz, unpaired/deleted every single device, rebooted, reactivated ZHA, unpaired/deleted every single device in ZHA, rebooted, and only paired three device. After another reboot I get again the same error messages:

2022-01-03 23:54:40 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140179872727584] Received invalid command: zha/devices/reconfigure
2022-01-03 23:54:41 WARNING (MainThread) [zigpy_deconz.zigbee.application] Unexpected transmit confirm for request id 195, Status: TXStatus.NWK_ROUTE_DISCOVERY_FAILED
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0000](dresden elektronik ConBee II) restored as 'available', last seen: 0:10:51 ago, consider_unavailable_time: 7200 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x99EB](Philips LTW010) restored as 'available', last seen: 0:01:05 ago, consider_unavailable_time: 7200 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xBA5B](Philips LTW010) restored as 'available', last seen: 0:02:19 ago, consider_unavailable_time: 7200 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xCB37](Philips LTW010) restored as 'available', last seen: 0:01:51 ago, consider_unavailable_time: 7200 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xBD8B](MLI ZBT-ExtendedColor) restored as 'available', last seen: 0:01:59 ago, consider_unavailable_time: 7200 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xB8F7](innr RB 185 C) restored as 'available', last seen: 0:01:59 ago, consider_unavailable_time: 7200 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x65FB](IKEA of Sweden TRADFRI on/off switch) restored as 'available', last seen: 0:47:59 ago, consider_unavailable_time: 21600 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x2F2F](LUMI lumi.sensor_motion.aq2) restored as 'available', last seen: 0:29:01 ago, consider_unavailable_time: 21600 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xDF8F](LUMI lumi.sensor_motion) restored as 'available', last seen: 0:29:01 ago, consider_unavailable_time: 21600 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0xDDA9](MLI ZBT-ColorTemperature) restored as 'available', last seen: 0:36:58 ago, consider_unavailable_time: 7200 seconds
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Group: No name group 0xFFF0:0xfff0 has less than 2 members - skipping entity discovery
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] Loading battery powered devices
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x65FB](TRADFRI on/off switch): started initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:ZDO](TRADFRI on/off switch): 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F2F](lumi.sensor_motion.aq2): started initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:ZDO](lumi.sensor_motion.aq2): 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x1000]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x1000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0001]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0001]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0000]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0020]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0020]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0102]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0102]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0008]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0008]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0006]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0006]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0019]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0019]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0001]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0001]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0500]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0500]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0000]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0406]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0406]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0400]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0400]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0019]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0019]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x1000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0001]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0020]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0102]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0008]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0006]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x65FB:1:0x0019]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0001]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0500]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0406]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0400]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2F2F:1:0x0019]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x65FB](TRADFRI on/off switch): power source: Battery or Unknown
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x65FB](TRADFRI on/off switch): completed initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F2F](lumi.sensor_motion.aq2): power source: Battery or Unknown
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x2F2F](lumi.sensor_motion.aq2): completed initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xDF8F](lumi.sensor_motion): started initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:ZDO](lumi.sensor_motion): 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0001]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0001]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0500]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0500]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0000]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0406]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0406]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0019]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0019]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0005]: initializing channel: from_cache: True
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0005]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0001]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0500]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0406]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0019]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDF8F:1:0x0005]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xDF8F](lumi.sensor_motion): power source: Battery or Unknown
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xDF8F](lumi.sensor_motion): completed initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] Loading mains powered devices
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](ConBee II): started initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:ZDO](ConBee II): 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x99EB](LTW010): started initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:ZDO](LTW010): 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:1:0x0000]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:1:0x0000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0006]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x0000:1:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](ConBee II): power source: Mains
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x0000](ConBee II): completed initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBA5B](LTW010): started initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:ZDO](LTW010): 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0006]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0006]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x1000]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x1000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0000]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0019]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0019]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0008]: received attribute: 0 update with value: 108
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0008]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0300]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0006]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0008]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0300]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x1000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x99EB:11:0x0019]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x99EB](LTW010): power source: Mains
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0x99EB](LTW010): completed initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xCB37](LTW010): started initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:ZDO](LTW010): 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0006]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0006]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x1000]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x1000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0000]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0000]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0019]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0019]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0008]: received attribute: 0 update with value: 102
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0008]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0300]: finished channel initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0006]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0008]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0300]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x1000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBA5B:11:0x0019]: 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBA5B](LTW010): power source: Mains
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBA5B](LTW010): completed initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBD8B](ZBT-ExtendedColor): started initialization
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:ZDO](ZBT-ExtendedColor): 'async_initialize' stage succeeded
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0006]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0006]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x1000]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x1000]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0000]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0000]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0019]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0019]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0008]: received attribute: 0 update with value: 102
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0008]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0300]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0006]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0008]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0300]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x1000]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xCB37:11:0x0019]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xCB37](LTW010): power source: Mains
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xCB37](LTW010): completed initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xB8F7](RB 185 C): started initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:ZDO](RB 185 C): 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0006]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0006]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x1000]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x1000]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0000]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0000]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0019]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0019]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0008]: received attribute: 0 update with value: 254
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0008]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0300]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0006]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0008]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0300]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x1000]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xBD8B:1:0x0019]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBD8B](ZBT-ExtendedColor): power source: Mains
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xBD8B](ZBT-ExtendedColor): completed initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xDDA9](ZBT-ColorTemperature): started initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:ZDO](ZBT-ColorTemperature): 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0006]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0006]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0000]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0000]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0019]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0019]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:2:0x1000]: initializing channel: from_cache: False
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:2:0x1000]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:2:0x1000]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: failed to get attributes '['current_level']' on 'level' cluster: [0xdda9:1:0x0008]: Message send failure
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: async_initialize: retryable request #1 failed: [0xdda9:1:0x0008]: Message send failure. Retrying in 1.2s
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: failed to get attributes '['color_loop_active', 'current_x', 'current_y', 'color_temperature']' on 'light_color' cluster: [0xdda9:1:0x0300]: Message send failure
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: async_initialize: retryable request #1 failed: [0xdda9:1:0x0300]: Message send failure. Retrying in 1.2s
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0008]: received attribute: 0 update with value: 254
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0008]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0300]: finished channel initialization
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0006]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0008]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0300]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0000]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB8F7:1:0x0019]: 'async_initialize' stage succeeded
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xB8F7](RB 185 C): power source: Mains
2022-01-03 23:54:42 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xB8F7](RB 185 C): completed initialization
2022-01-03 23:54:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: failed to get attributes '['color_loop_active', 'current_x', 'current_y', 'color_temperature']' on 'light_color' cluster: [0xdda9:1:0x0300]: Message send failure
2022-01-03 23:54:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: async_initialize: retryable request #2 failed: [0xdda9:1:0x0300]: Message send failure. Retrying in 1.2s
2022-01-03 23:54:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: failed to get attributes '['current_level']' on 'level' cluster: [0xdda9:1:0x0008]: Message send failure
2022-01-03 23:54:43 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: async_initialize: retryable request #2 failed: [0xdda9:1:0x0008]: Message send failure. Retrying in 1.0s
2022-01-03 23:54:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: failed to get attributes '['current_level']' on 'level' cluster: [0xdda9:1:0x0008]: Message send failure
2022-01-03 23:54:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: async_initialize: retryable request #3 failed: [0xdda9:1:0x0008]: Message send failure. Retrying in 3.6s
2022-01-03 23:54:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: failed to get attributes '['color_loop_active', 'current_x', 'current_y', 'color_temperature']' on 'light_color' cluster: [0xdda9:1:0x0300]: Message send failure
2022-01-03 23:54:44 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: async_initialize: retryable request #3 failed: [0xdda9:1:0x0300]: Message send failure. Retrying in 2.4s
2022-01-03 23:54:47 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: initializing channel: from_cache: False
2022-01-03 23:54:47 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: failed to get attributes '['color_loop_active', 'current_x', 'current_y', 'color_temperature']' on 'light_color' cluster: [0xdda9:1:0x0300]: Message send failure
2022-01-03 23:54:47 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0300]: async_initialize: all attempts have failed: [DeliveryError('[0xdda9:1:0x0300]: Message send failure'), DeliveryError('[0xdda9:1:0x0300]: Message send failure'), DeliveryError('[0xdda9:1:0x0300]: Message send failure'), DeliveryError('[0xdda9:1:0x0300]: Message send failure')]
2022-01-03 23:54:47 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x1000]: initializing channel: from_cache: False
2022-01-03 23:54:47 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x1000]: finished channel initialization
2022-01-03 23:54:47 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0000]: initializing channel: from_cache: False
2022-01-03 23:54:47 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0000]: finished channel initialization
2022-01-03 23:54:47 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0019]: initializing channel: from_cache: False
2022-01-03 23:54:47 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0019]: finished channel initialization
2022-01-03 23:54:48 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: initializing channel: from_cache: False
2022-01-03 23:54:48 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: failed to get attributes '['current_level']' on 'level' cluster: [0xdda9:1:0x0008]: Message send failure
2022-01-03 23:54:48 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xDDA9:1:0x0008]: async_initialize: all attempts have failed: [DeliveryError('[0xdda9:1:0x0008]: Message send failure'), DeliveryError('[0xdda9:1:0x0008]: Message send failure'), DeliveryError('[0xdda9:1:0x0008]: Message send failure'), DeliveryError('[0xdda9:1:0x0008]: Message send failure')]
maxshcherbina commented 2 years ago

My ZHA takes 172.51s to start.

I have the following logs:

2022-01-06 16:03:44 WARNING (MainThread) [zigpy.application] Device is partially initialized: <DeconzDevice model='ConBee II' manuf='dresden elektronik' nwk=0x0000 ieee=............. is_initialized=False>

There are times when my Deconz stick is shown as Offline despite working perfectly.

Apart from that, everything seems to be fine - just the long startup.

michaelarnauts commented 2 years ago

I see this also (recently moved from deconz to zha), but I'm wondering if this issue has always been present, but less noticeable when using the Deconz addon. Before ZHA, deconz was running in it's own container, and this wasn't restarted when HA restarts, only when the actual host is restarted.

DanDon commented 2 years ago

I also have this issue ... since the 2021.12 updates I have been getting very slow HA reboot times and startups.

I also get the same errors in the log. Didn't used to happen before and I have not changed any hardware or setup or added or removed any devices!

Hedda commented 2 years ago

I don't have a ConBee/RaspBee myself but a tip heard is that you will need to enable "source routing" if you got many devices.

https://community.home-assistant.io/t/zha-conbee-ii-source-routing/270711

I am however not sure if zigpy-deconz library support "source routing" yet if it was not available in earlier releases:

https://github.com/zigpy/zigpy-deconz

https://github.com/zigpy/zigpy-deconz/issues/180

PS: dresden elektronik own deCONZ/Phoscon automatically enables "source routing" when it is needed since v2.8.0

https://github.com/dresden-elektronik/deconz-rest-plugin/wiki/Source-Routing

https://phoscon.de/en/changelog

cunderw commented 2 years ago

I can confirm that I am also having this problem. Not 100% sure when it started, but on startup I am flooded with logs like this:

2022-02-14 11:56:55 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x949B:11:0x0008]: async_initialize: all attempts have failed: [DeliveryError('[0x949b:11:0x0008]: Message send failure'), DeliveryError('[0x949b:11:0x0008]: Message send failure'), DeliveryError('[0x949b:11:0x0008]: Message send failure'), DeliveryError('[0x949b:11:0x0008]: Message send failure')] 2022-02-14 11:56:55 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x949B:11:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x949b:11:0x0006]: Message send failure'), DeliveryError('[0x949b:11:0x0006]: Message send failure'), DeliveryError('[0x949b:11:0x0006]: Message send failure'), DeliveryError('[0x949b:11:0x0006]: Message send failure')] 2022-02-14 11:57:08 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA0A:11:0x0008]: async_initialize: all attempts have failed: [TimeoutError(), TimeoutError(), TimeoutError(), TimeoutError()] 2022-02-14 11:57:09 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xFA0A:11:0x0006]: async_initialize: all attempts have failed: [TimeoutError(), TimeoutError(), TimeoutError(), TimeoutError()] 2022-02-14 11:57:20 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x170B:1:0x0008]: async_initialize: all attempts have failed: [DeliveryError('[0x170b:1:0x0008]: Message send failure'), DeliveryError('[0x170b:1:0x0008]: Message send failure'), DeliveryError('[0x170b:1:0x0008]: Message send failure'), DeliveryError('[0x170b:1:0x0008]: Message send failure')] 2022-02-14 11:57:21 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x170B:1:0x0702]: async_initialize: all attempts have failed: [DeliveryError('[0x170b:1:0x0702]: Message send failure'), DeliveryError('[0x170b:1:0x0702]: Message send failure'), DeliveryError('[0x170b:1:0x0702]: Message send failure'), DeliveryError('[0x170b:1:0x0702]: Message send failure')] 2022-02-14 11:57:22 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xAC1A:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0xac1a:1:0x0006]: Message send failure'), DeliveryError('[0xac1a:1:0x0006]: Message send failure'), DeliveryError('[0xac1a:1:0x0006]: Message send failure'), DeliveryError('[0xac1a:1:0x0006]: Message send failure')] 2022-02-14 11:57:27 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xB9B3:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0xb9b3:1:0x0006]: Message send failure'), DeliveryError('[0xb9b3:1:0x0006]: Message send failure'), DeliveryError('[0xb9b3:1:0x0006]: Message send failure'), DeliveryError('[0xb9b3:1:0x0006]: Message send failure')] 2022-02-14 11:57:33 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x6E0B:1:0x0008]: async_initialize: all attempts have failed: [DeliveryError('[0x6e0b:1:0x0008]: Message send failure'), DeliveryError('[0x6e0b:1:0x0008]: Message send failure'), DeliveryError('[0x6e0b:1:0x0008]: Message send failure'), DeliveryError('[0x6e0b:1:0x0008]: Message send failure')] 2022-02-14 11:57:34 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x6E0B:1:0x0702]: async_initialize: all attempts have failed: [DeliveryError('[0x6e0b:1:0x0702]: Message send failure'), DeliveryError('[0x6e0b:1:0x0702]: Message send failure'), DeliveryError('[0x6e0b:1:0x0702]: Message send failure'), DeliveryError('[0x6e0b:1:0x0702]: Message send failure')] 2022-02-14 11:57:34 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x6E0B:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x6e0b:1:0x0006]: Message send failure'), DeliveryError('[0x6e0b:1:0x0006]: Message send failure'), DeliveryError('[0x6e0b:1:0x0006]: Message send failure'), DeliveryError('[0x6e0b:1:0x0006]: Message send failure')] 2022-02-14 11:58:13 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x0D35:1:0x0008]: async_initialize: all attempts have failed: [DeliveryError('[0x0d35:1:0x0008]: Message send failure'), DeliveryError('[0x0d35:1:0x0008]: Message send failure'), DeliveryError('[0x0d35:1:0x0008]: Message send failure'), DeliveryError('[0x0d35:1:0x0008]: Message send failure')] 2022-02-14 11:58:13 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x0D35:1:0x0300]: async_initialize: all attempts have failed: [DeliveryError('[0x0d35:1:0x0300]: Message send failure'), DeliveryError('[0x0d35:1:0x0300]: Message send failure'), DeliveryError('[0x0d35:1:0x0300]: Message send failure'), DeliveryError('[0x0d35:1:0x0300]: Message send failure')] 2022-02-14 11:58:18 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x0D35:1:0x0702]: async_initialize: all attempts have failed: [DeliveryError('[0x0d35:1:0x0702]: Message send failure'), DeliveryError('[0x0d35:1:0x0702]: Message send failure'), DeliveryError('[0x0d35:1:0x0702]: Message send failure'), DeliveryError('[0x0d35:1:0x0702]: Message send failure')] 2022-02-14 11:58:19 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x170B:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('[0x170b:1:0x0006]: Message send failure'), DeliveryError('[0x170b:1:0x0006]: Message send failure'), TimeoutError(), DeliveryError('[0x170b:1:0x0006]: Message send failure')]

core-2022.2.6 supervisor-2022.01.1

After about five minutes of this everything starts working again.

Hedda commented 2 years ago

I've done further testing and researched further - plus upgraded to a Sonoff Zigbee 3.0 Plus from a Conbee II.

The delay is still present - Zigbee devices don't become available until 6 minutes after a HA restart.

I think the issue is that ~a dozen of my smart bulbs are on hard wall switches, so if they are turned off at the switch, the zha bulbs are never seen by HA. HA continues to try and find the devices (5 times?) and I think that may be the issue here.

I tested this theory and restarted HA with all zha devices on and accessible. Sure enough, I cut the delay down to under a minute.

I will say that this same zha config with older HA versions (early 2021?) was available quicker through the UI- even if they were unreachable - than later 2021 versions.

FYI, there is also known issues with ConBee USB adapter sometimes needing to be unplugged and reinserted after a restart of HA. If that is the case then might be a good idea to also report to https://github.com/dresden-elektronik/deconz-rest-plugin/issues (?).

Also, before even starting troubleshooting recommend following the guidelines here -> https://github.com/home-assistant/home-assistant.io/pull/18864 as that will at the very least probably reduce most errors and failures caused by a noisy environment due to RFI/EMI interference. Even if it is not the root cause for this issue, trying to reduce sources of interference should hopefully help further troubleshooting.

Short summary of best practices on how to achieve a stable Zigbee setup and a robust Zigbee network mesh:

Zigbee and especially the Zigbee Coordinator are known to be very susceptible to Radio Frequency Interference (RFI) / Electromagnetic interference (EMI) caused by different signal interfering sources, so most general tips is to try to reduce interference meant to be taken seriously and it is very important to follow those best practice guidelines even if they may sound silly at a glance.

A lot of ZHA and Zigbee2MQTT users and especially those with ConBee/RaspBerry based Zigbee Coordinator adapters have posted in the Home Assistant community forum reporting with similar symptoms or other types of connection problems with Zigbee devices and for many of those issues the root cause turned out to be RFI/EMI interference and the users reported that the problem was resolved by simply getting both the Zigbee Coordinator and devices a bit away from all possible sources of RFI/EMI interference.

  1. Upgrade to the latest firmware on the Zigbee Coordinator adapter (whichever adapter you have). For ConBee/RaspBerry see:
  2. Connect the Zigbee Coordinator adapter to a long USB extension cable to get it a bit away from computer and peripherals.
  3. Connect the Zigbee Coordinator adapter to a USB 2.0 port (or via USB 2.0 hub, because USB 3.0 ports do cause interference).
  4. Shield any computers and USB 3.0 peripherals like hard drives by using metal enclosures/cases for computer and peripherals.
  5. Make sure that your Zigbee Coordinator adapter and devices are not close to your WiFi Router or any WiFi Access Points.
  6. Zigbee devices do not have long-range (or good radio signal penetration) on their own so begin by successively adding more always-on mains-powered Zigbee Router devices (a.k.a. Zigbee signal-repeaters/range-extenders) closer to the Zigbee Coordinator adapter and then in each room building outwards to form a stable Zigbee network mesh before adding devices further way. Note! Remember that Zigbee Router devices should be installed with permanent power so they are always available.
  7. Afting adding always-on mains-powered Zigbee Router devices pair all the other devices (Zigbee end-device devices) such as example battery-powered sensors where you plan to have them permanently installed and do not move them around afterwards.
  8. If still have issues change Wi-Fi channel(s) on your WiFi router or WiFi access points to do not conflict with Zigbee -> https://www.metageek.com/training/resources/zigbee-wifi-coexistence/
  9. If still have a problem then consider changing Zigbee channel to channel 25 at the risk of then no longer being compatible with older Zigbee devices, also noting that changing Zigbee channel could mean that have to re-pair all or some devices.

PS: I appreciate it if you guys give a thumbs up to this PR if these guidelines help you -> https://github.com/home-assistant/home-assistant.io/pull/18864

cunderw commented 2 years ago

I've done further testing and researched further - plus upgraded to a Sonoff Zigbee 3.0 Plus from a Conbee II. The delay is still present - Zigbee devices don't become available until 6 minutes after a HA restart. I think the issue is that ~a dozen of my smart bulbs are on hard wall switches, so if they are turned off at the switch, the zha bulbs are never seen by HA. HA continues to try and find the devices (5 times?) and I think that may be the issue here. I tested this theory and restarted HA with all zha devices on and accessible. Sure enough, I cut the delay down to under a minute. I will say that this same zha config with older HA versions (early 2021?) was available quicker through the UI- even if they were unreachable - than later 2021 versions.

FYI, there is also known issues with ConBee USB adapter sometimes needing to be unplugged and reinserted after a restart of HA. If that is the case then might be a good idea to also report to https://github.com/dresden-elektronik/deconz-rest-plugin/issues (?).

Also, before even starting troubleshooting recommend following the guidelines here -> home-assistant/home-assistant.io#18864 as that will at the very least probably reduce most errors and failures caused by a noisy environment due to RFI/EMI interference. Even if it is not the root cause for this issue, trying to reduce sources of interference should hopefully help further troubleshooting.

Short summary of best practices on how to achieve a stable Zigbee setup and a robust Zigbee network mesh:

Zigbee and especially the Zigbee Coordinator are known to be very susceptible to Radio Frequency Interference (RFI) / Electromagnetic interference (EMI) caused by different signal interfering sources, so most general tips is to try to reduce interference meant to be taken seriously and it is very important to follow those best practice guidelines even if they may sound silly at a glance.

A lot of ZHA and Zigbee2MQTT users and especially those with ConBee/RaspBerry based Zigbee Coordinator adapters have posted in the Home Assistant community forum reporting with similar symptoms or other types of connection problems with Zigbee devices and for many of those issues the root cause turned out to be RFI/EMI interference and the users reported that the problem was resolved by simply getting both the Zigbee Coordinator and devices a bit away from all possible sources of RFI/EMI interference.

  1. Upgrade to the latest firmware on the Zigbee Coordinator adapter (whichever adapter you have). For ConBee/RaspBerry firmware see for example -> https://flemmingss.com/how-to-update-conbee-conbee-ii-firmware-in-windows-10/
  2. Connect the Zigbee Coordinator adapter to a long USB extension cable to get it a bit away from computer and peripherals.
  3. Connect the Zigbee Coordinator adapter to a USB 2.0 port (or via USB 2.0 hub, because USB 3.0 ports do cause interference).
  4. Shield any computers and USB 3.0 peripherals like hard drives by using metal enclosures/cases for computer and peripherals.
  5. Make sure that your Zigbee Coordinator adapter and devices are not close to your WiFi Router or any WiFi Access Points.
  6. Zigbee devices do not have long-range (or good radio signal penetration) on their own so begin by successively adding more always-on mains-powered Zigbee Router devices (a.k.a. Zigbee signal-repeaters/range-extenders) closer to the Zigbee Coordinator adapter and then in each room building outwards to form a stable Zigbee network mesh before adding devices further way. Note! Remember that Zigbee Router devices should be installed with permanent power so they are always available.
  7. Afting adding always-on mains-powered Zigbee Router devices pair all the other devices (Zigbee end-device devices) such as example battery-powered sensors where you plan to have them permanently installed and do not move them around afterwards.
  8. If still have issues change Wi-Fi channel(s) on your WiFi router or WiFi access points to do not conflict with Zigbee -> https://www.metageek.com/training/resources/zigbee-wifi-coexistence/
  9. If still have a problem then consider changing Zigbee channel to channel 25 at the risk of then no longer being compatible with older Zigbee devices, also noting that changing Zigbee channel could mean that have to re-pair all or some devices.

PS: I appreciate it if you guys give a thumbs up to this PR if these guidelines help you -> home-assistant/home-assistant.io#18864

This is great advice, but does not address the issue some of us our seeing. For me it is only right after a reboot, once it settles down everything works just fine. This used to never happen, I am not sure when it started, but something has definitely changed and it's not my hardware.

pfak commented 2 years ago

It looks like the devices are serially initialized on startup. I have ~105 devices, and it takes almost 5 minutes (and grows every time I add a device) for the mains powered devices. The battery powered ones are loaded from cache, but they still aren't available until ZHA has queried each device mains powered device.

I am using a Sonoff Zigbee 3.0 USB adapter (with CC1352P2_CC2652P_launchpad_coordinator_20211217 flashed.)

It seems to restore the devices via async_load_devices from zigpy application state, but then serially loads each of them again before making them available.

pfak commented 2 years ago

https://github.com/home-assistant/core/blob/dev/homeassistant/components/zha/core/gateway.py#L212

Is there a particular reason we only have 2 semaphores for startup? I increased this number to 4 and cut the init time for all entities to be available in half.

Any higher value seems to not increase performance, as the setup is waiting for the remaining items to time out when unavailable before making online entities available (not sure this behaviour is desirable?)

Sjorsa commented 2 years ago

I have started seeing the same behaviour since a month or 2 maybe. My aqara temperature sensors show unavailable after a reboot. They become available after a few minutes, I assume whenever they push a new value to ZHA. I have one of the temp sensors integrated in a virtual climate entity, so whenever the sensor becomes unavailable, the heater turns off.

turbo4door commented 2 years ago

Add me to the list of those experiencing this issue as well. I have 21 Zigbee devices and it takes them about 4 or 5 minutes to become available AFTER Home Assistant starts. This was never the case and there have been no changes to my setup other than regular HA updates. This started a month or two ago for me as best I can tell.

RPI4 with HUSBZB-1 Adapter. I've done all the standard ZigBee troubleshooting and the coordinator is connected via a USB extension cable.

dmulcahey commented 2 years ago

The slow boot issues are caused by offline or unreachable mains powered devices. When we introduced support for multiple entities per cluster we had to increase the amount of attribute data we read from the devices. That increase coupled with the retries we perform to account for occasional messages failing are what causes this delay.

There isn’t a good solution to this issue. For networks that are stable with no offline devices these changes were negligible. For weak meshes / networks with many offline mains powered devices we have heard that what is outlined here is common. The main issue stems from the fact that we aren’t expecting mains powered devices to be offline.

it has been suggested that we offer a config to skip polling mains powered devices. I’m hesitant to do this because it will lead to state desync issues with the HA UI after rebooting. There is no good way to determine that a user has turned off the power to mains powered devices so the option would have to be per device and user set or global. I’m not a fan of either option.

Hedda commented 2 years ago

Maybe https://github.com/zigpy/zigpy-deconz/pull/182 will help shorten down some problems caused by routing issues when the Conbee first starts up?

Note that that PR is however not yet part of a new release of zigpy-deconz -> https://github.com/zigpy/zigpy-deconz/releases

By the way, related deconz source routing verses deconz manual routing topic was/is discussed here -> https://github.com/zigpy/zigpy-deconz/issues/180

github-actions[bot] commented 2 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.