core
core copied to clipboard
Published
20 hours ago •
home-assistant
home-assistant
zha: Error setting up OnOffClusterHandler
The problem
KeyError: 'on_off' occurs after upgrade to 2023.5 beta.
What version of Home Assistant Core has the issue?
2023.5.0b2
What was the last working version of Home Assistant Core?
2023.4
What type of installation are you running?
Home Assistant Core
Integration causing the issue
zha
Link to integration documentation on our website
No response
Diagnostics information
Logger: homeassistant.config_entries
Source: components/zha/core/cluster_handlers/__init__.py:133
First occurred: 00:59:09 (1 occurrences)
Last logged: 00:59:09
Error setting up entry SONOFF Zigbee 3.0 USB Dongle Plus V2, s/n: 20221202181808 - ITEAD for zha
Traceback (most recent call last):
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/config_entries.py", line 387, in async_setup
result = await component.async_setup_entry(hass, self)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/__init__.py", line 122, in async_setup_entry
await zha_gateway.async_initialize()
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/gateway.py", line 230, in async_initialize
self.async_load_devices()
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/gateway.py", line 238, in async_load_devices
zha_device = self._async_get_or_create_device(zigpy_device, restored=True)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/gateway.py", line 570, in _async_get_or_create_device
zha_device = ZHADevice.new(self._hass, zigpy_device, self, restored)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/device.py", line 408, in new
zha_dev = cls(hass, zigpy_dev, gateway)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/device.py", line 153, in __init__
self._endpoints[ep_id] = Endpoint.new(endpoint, self)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/endpoint.py", line 109, in new
endpoint.add_all_cluster_handlers()
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/endpoint.py", line 140, in add_all_cluster_handlers
cluster_handler = cluster_handler_class(cluster, self)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/cluster_handlers/general.py", line 358, in __init__
super().__init__(cluster, endpoint)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 133, in __init__
attr_def: ZCLAttributeDef = self.cluster.attributes_by_name[
KeyError: 'on_off'
Example YAML snippet
No response
Anything in the logs that might be useful for us?
No response
Additional information
No response
Hey there @dmulcahey, @adminiuga, @puddly, 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!
Code owner commands
Code owners of zha can trigger bot actions by commenting:
-
@home-assistant closeCloses the issue. -
@home-assistant rename Awesome new titleRenames the issue. -
@home-assistant reopenReopen the issue. -
@home-assistant unassign zhaRemoves the current integration label and assignees on the issue, add the integration domain after the command.
(message by CodeOwnersMention)
zha documentation zha source (message by IssueLinks)
![home-assistant[bot] avatar](https://avatars.githubusercontent.com/in/97978?v=4 "Published by a pub.dev verified publisher"){kind=small}
Could you enable https://www.home-assistant.io/integrations/zha/#debug-logging and post the startup debug log?
Also, are you running any custom quirks? I believe this problem was fixed in 2023.5.0b2.
Hi, thanks! Sorry for late response, I just tested on 2023.5.0b6 and this still occurs.
2023-05-02 12:57:49.450 DEBUG (MainThread) [bellows.ezsp.protocol] Send command version: (4,)
2023-05-02 12:57:49.457 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received version: [8, 2, 27184]
2023-05-02 12:57:49.460 DEBUG (MainThread) [bellows.ezsp] Switching to EZSP protocol version 8
2023-05-02 12:57:49.462 DEBUG (MainThread) [bellows.ezsp.protocol] Send command version: (8,)
2023-05-02 12:57:49.474 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received version: [8, 2, 27184]
2023-05-02 12:57:49.477 DEBUG (MainThread) [bellows.ezsp] EZSP Stack Type: 2, Stack Version: 6a30, Protocol version: 8
2023-05-02 12:57:49.485 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_SOURCE_ROUTE_TABLE_SIZE: 26>,)
2023-05-02 12:57:49.494 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 200]
2023-05-02 12:57:49.495 DEBUG (MainThread) [bellows.ezsp.protocol] Current config CONFIG_SOURCE_ROUTE_TABLE_SIZE = 200 exceeds the default of 200, skipping
2023-05-02 12:57:49.495 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_END_DEVICE_POLL_TIMEOUT: 19>,)
2023-05-02 12:57:49.508 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 8]
2023-05-02 12:57:49.508 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_END_DEVICE_POLL_TIMEOUT = 8 (old value 8)
2023-05-02 12:57:49.508 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_END_DEVICE_POLL_TIMEOUT: 19>, 8)
2023-05-02 12:57:49.518 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.523 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_INDIRECT_TRANSMISSION_TIMEOUT: 18>,)
2023-05-02 12:57:49.533 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 3000]
2023-05-02 12:57:49.534 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_INDIRECT_TRANSMISSION_TIMEOUT = 7680 (old value 3000)
2023-05-02 12:57:49.534 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_INDIRECT_TRANSMISSION_TIMEOUT: 18>, 7680)
2023-05-02 12:57:49.546 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.546 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_STACK_PROFILE: 12>,)
2023-05-02 12:57:49.555 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 0]
2023-05-02 12:57:49.557 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_STACK_PROFILE = 2 (old value 0)
2023-05-02 12:57:49.557 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_STACK_PROFILE: 12>, 2)
2023-05-02 12:57:49.566 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.567 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_SUPPORTED_NETWORKS: 45>,)
2023-05-02 12:57:49.578 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 1]
2023-05-02 12:57:49.581 DEBUG (MainThread) [bellows.ezsp.protocol] Current config CONFIG_SUPPORTED_NETWORKS = 1 exceeds the default of 1, skipping
2023-05-02 12:57:49.582 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_MULTICAST_TABLE_SIZE: 6>,)
2023-05-02 12:57:49.593 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 8]
2023-05-02 12:57:49.595 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_MULTICAST_TABLE_SIZE = 16 (old value 8)
2023-05-02 12:57:49.595 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_MULTICAST_TABLE_SIZE: 6>, 16)
2023-05-02 12:57:49.617 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.618 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE: 25>,)
2023-05-02 12:57:49.625 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 0]
2023-05-02 12:57:49.627 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE = 2 (old value 0)
2023-05-02 12:57:49.628 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE: 25>, 2)
2023-05-02 12:57:49.652 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.653 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_SECURITY_LEVEL: 13>,)
2023-05-02 12:57:49.661 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 5]
2023-05-02 12:57:49.663 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_SECURITY_LEVEL = 5 (old value 5)
2023-05-02 12:57:49.663 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_SECURITY_LEVEL: 13>, 5)
2023-05-02 12:57:49.677 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.678 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_ADDRESS_TABLE_SIZE: 5>,)
2023-05-02 12:57:49.688 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 32]
2023-05-02 12:57:49.689 DEBUG (MainThread) [bellows.ezsp.protocol] Current config CONFIG_ADDRESS_TABLE_SIZE = 32 exceeds the default of 16, skipping
2023-05-02 12:57:49.689 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_TC_REJOINS_USING_WELL_KNOWN_KEY_TIMEOUT_S: 56>,)
2023-05-02 12:57:49.697 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 300]
2023-05-02 12:57:49.699 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_TC_REJOINS_USING_WELL_KNOWN_KEY_TIMEOUT_S = 90 (old value 300)
2023-05-02 12:57:49.699 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_TC_REJOINS_USING_WELL_KNOWN_KEY_TIMEOUT_S: 56>, 90)
2023-05-02 12:57:49.711 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.712 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_PAN_ID_CONFLICT_REPORT_THRESHOLD: 34>,)
2023-05-02 12:57:49.720 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 2]
2023-05-02 12:57:49.722 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_PAN_ID_CONFLICT_REPORT_THRESHOLD = 2 (old value 2)
2023-05-02 12:57:49.722 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_PAN_ID_CONFLICT_REPORT_THRESHOLD: 34>, 2)
2023-05-02 12:57:49.731 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.732 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_APPLICATION_ZDO_FLAGS: 42>,)
2023-05-02 12:57:49.739 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 0]
2023-05-02 12:57:49.741 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_APPLICATION_ZDO_FLAGS = EmberZdoConfigurationFlags.APP_HANDLES_UNSUPPORTED_ZDO_REQUESTS|APP_RECEIVES_SUPPORTED_ZDO_REQUESTS (old value 0)
2023-05-02 12:57:49.741 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_APPLICATION_ZDO_FLAGS: 42>, <EmberZdoConfigurationFlags.APP_HANDLES_UNSUPPORTED_ZDO_REQUESTS|APP_RECEIVES_SUPPORTED_ZDO_REQUESTS: 3>)
2023-05-02 12:57:49.750 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.751 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_PACKET_BUFFER_COUNT: 1>,)
2023-05-02 12:57:49.760 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 250]
2023-05-02 12:57:49.762 DEBUG (MainThread) [bellows.ezsp.protocol] Setting config CONFIG_PACKET_BUFFER_COUNT = 255 (old value 250)
2023-05-02 12:57:49.762 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setConfigurationValue: (<EzspConfigId.CONFIG_PACKET_BUFFER_COUNT: 1>, 255)
2023-05-02 12:57:49.782 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setConfigurationValue: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.783 DEBUG (MainThread) [bellows.ezsp.protocol] Send command addEndpoint: (1, 260, <DeviceType.IAS_CONTROL: 1024>, 0, 5, 4, [0, 6, 10, 25, 1281], [1, 32, 1280, 1282])
2023-05-02 12:57:49.796 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received addEndpoint: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.798 DEBUG (MainThread) [bellows.zigbee.application] Ezsp adding endpoint: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.798 DEBUG (MainThread) [bellows.ezsp.protocol] Send command addEndpoint: (2, 49246, <DeviceType.CONTROLLER: 2080>, 0, 1, 0, [0], [])
2023-05-02 12:57:49.811 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received addEndpoint: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.812 DEBUG (MainThread) [bellows.zigbee.application] Ezsp adding endpoint: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:49.812 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_STRING: 1>,)
2023-05-02 12:57:49.823 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMfgToken: [b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff']
2023-05-02 12:57:49.825 DEBUG (MainThread) [bellows.ezsp] Read MFG_STRING token: b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff'
2023-05-02 12:57:49.825 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_BOARD_NAME: 2>,)
2023-05-02 12:57:49.836 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMfgToken: [b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff']
2023-05-02 12:57:49.837 DEBUG (MainThread) [bellows.ezsp] Read MFG_BOARD_NAME token: b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff'
2023-05-02 12:57:49.837 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_VERSION_INFO: 17>,)
2023-05-02 12:57:49.846 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b')\x01\x06\n\x03\x00\xaa']
2023-05-02 12:57:49.846 INFO (MainThread) [bellows.zigbee.application] EZSP Radio manufacturer:
2023-05-02 12:57:49.847 INFO (MainThread) [bellows.zigbee.application] EZSP Radio board name:
2023-05-02 12:57:49.847 INFO (MainThread) [bellows.zigbee.application] EmberZNet version: 6.10.3.0 build 297
2023-05-02 12:57:49.847 DEBUG (MainThread) [bellows.ezsp.protocol] Send command networkState: ()
2023-05-02 12:57:49.855 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received networkState: [<EmberNetworkStatus.NO_NETWORK: 0>]
2023-05-02 12:57:49.855 DEBUG (MainThread) [bellows.ezsp.protocol] Send command networkInit: ()
2023-05-02 12:57:49.870 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received networkInit: [<EmberStatus.SUCCESS: 0>]
2023-05-02 12:57:49.870 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getNetworkParameters: ()
2023-05-02 12:57:49.872 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received stackStatusHandler: [<EmberStatus.NETWORK_UP: 144>]
2023-05-02 12:57:49.883 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getNetworkParameters: [<EmberStatus.SUCCESS: 0>, <EmberNodeType.COORDINATOR: 1>, EmberNetworkParameters(extendedPanId=30:c1:d3:9d:c0:9e:26:f1, panId=0x2096, radioTxPower=8, radioChannel=15, joinMethod=<EmberJoinMethod.USE_MAC_ASSOCIATION: 0>, nwkManagerId=0x0000, nwkUpdateId=0, channels=<Channels.ALL_CHANNELS: 134215680>)]
2023-05-02 12:57:49.884 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getNodeId: ()
2023-05-02 12:57:49.975 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getNodeId: [0x0000]
2023-05-02 12:57:49.983 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getEui64: ()
2023-05-02 12:57:49.991 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getEui64: [e0:79:8d:ff:fe:f8:a5:5c]
2023-05-02 12:57:49.992 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_SECURITY_LEVEL: 13>,)
2023-05-02 12:57:50.000 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 5]
2023-05-02 12:57:50.001 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getKey: (<EmberKeyType.CURRENT_NETWORK_KEY: 3>,)
2023-05-02 12:57:50.014 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getKey: [<EmberStatus.SUCCESS: 0>, EmberKeyStruct(bitmask=<EmberKeyStructBitmask.KEY_HAS_OUTGOING_FRAME_COUNTER|KEY_HAS_SEQUENCE_NUMBER: 3>, type=<EmberKeyType.CURRENT_NETWORK_KEY: 3>, key=[157, 137, 87, 19, 93, 42, 224, 142, 7, 143, 66, 101, 104, 229, 0, 123], outgoingFrameCounter=7409665, incomingFrameCounter=0, sequenceNumber=0, partnerEUI64=00:00:00:00:00:00:00:00)]
2023-05-02 12:57:50.015 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getKey: (<EmberKeyType.TRUST_CENTER_LINK_KEY: 1>,)
2023-05-02 12:57:50.029 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getKey: [<EmberStatus.SUCCESS: 0>, EmberKeyStruct(bitmask=<EmberKeyStructBitmask.KEY_IS_AUTHORIZED|KEY_HAS_PARTNER_EUI64|KEY_HAS_OUTGOING_FRAME_COUNTER: 26>, type=<EmberKeyType.TRUST_CENTER_LINK_KEY: 1>, key=[96, 251, 19, 170, 241, 164, 120, 225, 142, 100, 249, 234, 141, 244, 64, 33], outgoingFrameCounter=81920, incomingFrameCounter=0, sequenceNumber=0, partnerEUI64=e0:79:8d:ff:fe:f8:a5:5c)]
2023-05-02 12:57:50.030 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getCurrentSecurityState: ()
2023-05-02 12:57:50.039 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getCurrentSecurityState: [<EmberStatus.SUCCESS: 0>, EmberCurrentSecurityState(bitmask=<EmberCurrentSecurityBitmask.TRUST_CENTER_USES_HASHED_LINK_KEY|64|32|HAVE_TRUST_CENTER_LINK_KEY|GLOBAL_LINK_KEY: 244>, trustCenterLongAddress=e0:79:8d:ff:fe:f8:a5:5c)]
2023-05-02 12:57:50.040 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_STRING: 1>,)
2023-05-02 12:57:50.049 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMfgToken: [b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff']
2023-05-02 12:57:50.049 DEBUG (MainThread) [bellows.ezsp] Read MFG_STRING token: b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff'
2023-05-02 12:57:50.050 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_BOARD_NAME: 2>,)
2023-05-02 12:57:50.059 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMfgToken: [b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff']
2023-05-02 12:57:50.059 DEBUG (MainThread) [bellows.ezsp] Read MFG_BOARD_NAME token: b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff'
2023-05-02 12:57:50.060 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_VERSION_INFO: 17>,)
2023-05-02 12:57:50.068 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b')\x01\x06\n\x03\x00\xaa']
2023-05-02 12:57:50.069 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_CUSTOM_EUI_64: 12>,)
2023-05-02 12:57:50.076 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMfgToken: [b'\xff\xff\xff\xff\xff\xff\xff\xff']
2023-05-02 12:57:50.078 DEBUG (MainThread) [zigpy.application] Network info: NetworkInfo(extended_pan_id=30:c1:d3:9d:c0:9e:26:f1, pan_id=0x2096, nwk_update_id=0, nwk_manager_id=0x0000, channel=15, channel_mask=<Channels.ALL_CHANNELS: 134215680>, security_level=5, network_key=Key(key=9d:89:57:13:5d:2a:e0:8e:07:8f:42:65:68:e5:00:7b, tx_counter=7409665, rx_counter=0, seq=0, partner_ieee=ff:ff:ff:ff:ff:ff:ff:ff), tc_link_key=Key(key=5a:69:67:42:65:65:41:6c:6c:69:61:6e:63:65:30:39, tx_counter=81920, rx_counter=0, seq=0, partner_ieee=e0:79:8d:ff:fe:f8:a5:5c), key_table=[], children=[], nwk_addresses={}, stack_specific={'ezsp': {'hashed_tclk': '60fb13aaf1a478e18e64f9ea8df44021'}}, metadata={'ezsp': {'manufacturer': '', 'board': '', 'version': '6.10.3.0 build 297', 'stack_version': 8, 'can_write_custom_eui64': True}}, source='[email protected]')
2023-05-02 12:57:50.080 DEBUG (MainThread) [zigpy.application] Node info: NodeInfo(nwk=0x0000, ieee=e0:79:8d:ff:fe:f8:a5:5c, logical_type=<LogicalType.Coordinator: 0>)
2023-05-02 12:57:50.081 DEBUG (MainThread) [bellows.ezsp.protocol] Send command networkState: ()
2023-05-02 12:57:50.094 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received networkState: [<EmberNetworkStatus.JOINED_NETWORK: 2>]
2023-05-02 12:57:50.095 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.TC_KEY_REQUEST_POLICY: 5>, <EzspDecisionId.ALLOW_TC_KEY_REQUESTS: 81>)
2023-05-02 12:57:50.102 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setPolicy: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:50.103 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.TRUST_CENTER_POLICY: 0>, <EzspDecisionId.ALLOW_PRECONFIGURED_KEY_JOINS: 1>)
2023-05-02 12:57:50.112 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setPolicy: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:50.113 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.APP_KEY_REQUEST_POLICY: 6>, <EzspDecisionId.DENY_APP_KEY_REQUESTS: 96>)
2023-05-02 12:57:50.122 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setPolicy: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:50.123 DEBUG (MainThread) [bellows.ezsp.protocol] Send command networkState: ()
2023-05-02 12:57:50.129 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received networkState: [<EmberNetworkStatus.JOINED_NETWORK: 2>]
2023-05-02 12:57:50.129 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getNetworkParameters: ()
2023-05-02 12:57:50.139 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getNetworkParameters: [<EmberStatus.SUCCESS: 0>, <EmberNodeType.COORDINATOR: 1>, EmberNetworkParameters(extendedPanId=30:c1:d3:9d:c0:9e:26:f1, panId=0x2096, radioTxPower=8, radioChannel=15, joinMethod=<EmberJoinMethod.USE_MAC_ASSOCIATION: 0>, nwkManagerId=0x0000, nwkUpdateId=0, channels=<Channels.ALL_CHANNELS: 134215680>)]
2023-05-02 12:57:50.140 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getNodeId: ()
2023-05-02 12:57:50.150 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getNodeId: [0x0000]
2023-05-02 12:57:50.151 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getEui64: ()
2023-05-02 12:57:50.158 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getEui64: [e0:79:8d:ff:fe:f8:a5:5c]
2023-05-02 12:57:50.159 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_SECURITY_LEVEL: 13>,)
2023-05-02 12:57:50.166 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 5]
2023-05-02 12:57:50.167 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getKey: (<EmberKeyType.CURRENT_NETWORK_KEY: 3>,)
2023-05-02 12:57:50.181 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getKey: [<EmberStatus.SUCCESS: 0>, EmberKeyStruct(bitmask=<EmberKeyStructBitmask.KEY_HAS_OUTGOING_FRAME_COUNTER|KEY_HAS_SEQUENCE_NUMBER: 3>, type=<EmberKeyType.CURRENT_NETWORK_KEY: 3>, key=[157, 137, 87, 19, 93, 42, 224, 142, 7, 143, 66, 101, 104, 229, 0, 123], outgoingFrameCounter=7409665, incomingFrameCounter=0, sequenceNumber=0, partnerEUI64=00:00:00:00:00:00:00:00)]
2023-05-02 12:57:50.182 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getKey: (<EmberKeyType.TRUST_CENTER_LINK_KEY: 1>,)
2023-05-02 12:57:50.195 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getKey: [<EmberStatus.SUCCESS: 0>, EmberKeyStruct(bitmask=<EmberKeyStructBitmask.KEY_IS_AUTHORIZED|KEY_HAS_PARTNER_EUI64|KEY_HAS_OUTGOING_FRAME_COUNTER: 26>, type=<EmberKeyType.TRUST_CENTER_LINK_KEY: 1>, key=[96, 251, 19, 170, 241, 164, 120, 225, 142, 100, 249, 234, 141, 244, 64, 33], outgoingFrameCounter=81920, incomingFrameCounter=0, sequenceNumber=0, partnerEUI64=e0:79:8d:ff:fe:f8:a5:5c)]
2023-05-02 12:57:50.196 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getCurrentSecurityState: ()
2023-05-02 12:57:50.204 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getCurrentSecurityState: [<EmberStatus.SUCCESS: 0>, EmberCurrentSecurityState(bitmask=<EmberCurrentSecurityBitmask.TRUST_CENTER_USES_HASHED_LINK_KEY|64|32|HAVE_TRUST_CENTER_LINK_KEY|GLOBAL_LINK_KEY: 244>, trustCenterLongAddress=e0:79:8d:ff:fe:f8:a5:5c)]
2023-05-02 12:57:50.206 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_STRING: 1>,)
2023-05-02 12:57:50.216 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMfgToken: [b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff']
2023-05-02 12:57:50.217 DEBUG (MainThread) [bellows.ezsp] Read MFG_STRING token: b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff'
2023-05-02 12:57:50.217 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_BOARD_NAME: 2>,)
2023-05-02 12:57:50.226 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMfgToken: [b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff']
2023-05-02 12:57:50.227 DEBUG (MainThread) [bellows.ezsp] Read MFG_BOARD_NAME token: b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff'
2023-05-02 12:57:50.227 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getValue: (<EzspValueId.VALUE_VERSION_INFO: 17>,)
2023-05-02 12:57:50.236 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getValue: [<EzspStatus.SUCCESS: 0>, b')\x01\x06\n\x03\x00\xaa']
2023-05-02 12:57:50.238 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMfgToken: (<EzspMfgTokenId.MFG_CUSTOM_EUI_64: 12>,)
2023-05-02 12:57:50.246 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMfgToken: [b'\xff\xff\xff\xff\xff\xff\xff\xff']
2023-05-02 12:57:50.248 DEBUG (MainThread) [zigpy.device] [0x0000] Scheduling initialization
2023-05-02 12:57:50.250 DEBUG (MainThread) [bellows.zigbee.application] Starting EZSP watchdog
2023-05-02 12:57:50.250 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2023-05-02 12:57:50.250 INFO (MainThread) [zigpy.device] [0x0000] Requesting 'Node Descriptor'
2023-05-02 12:57:50.250 DEBUG (MainThread) [zigpy.util] Tries remaining: 2
2023-05-02 12:57:50.250 DEBUG (MainThread) [zigpy.device] [0x0000] Extending timeout for 0x01 request
2023-05-02 12:57:50.251 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=True, tsn=1, profile_id=0, cluster_id=<ZDOCmd.Node_Desc_req: 0x0002>, data=Serialized[b'\x01\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-05-02 12:57:50.253 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setExtendedTimeout: (e0:79:8d:ff:fe:f8:a5:5c, True)
2023-05-02 12:57:50.261 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setExtendedTimeout: []
2023-05-02 12:57:50.263 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x0000, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=1), 2, b'\x01\x00\x00')
2023-05-02 12:57:50.275 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 47]
2023-05-02 12:57:50.283 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=47), 255, 0, 0x0000, 255, 255, b'\x01\x00\x00']
2023-05-02 12:57:50.283 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=47), 255, 0, 0x0000, 255, 255, b'\x01\x00\x00']
2023-05-02 12:57:50.284 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=47, profile_id=0, cluster_id=2, data=Serialized[b'\x01\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=255, rssi=0)
2023-05-02 12:57:50.284 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model='EZSP' manuf='Silicon Labs' nwk=0x0000 ieee=e0:79:8d:ff:fe:f8:a5:5c is_initialized=False> from ep 0 to ep 0, cluster 2: b'\x01\x00\x00'
2023-05-02 12:57:50.285 DEBUG (MainThread) [zigpy.zdo] [0x0000:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000]
2023-05-02 12:57:50.285 DEBUG (MainThread) [zigpy.zdo] [0x0000:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000])
2023-05-02 12:57:50.293 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=47), 2, <EmberStatus.SUCCESS: 0>, b'']
2023-05-02 12:57:50.294 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0, EmberApsFrame(profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=47), 2, <EmberStatus.SUCCESS: 0>, b'']
2023-05-02 12:57:50.300 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32770, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=48), 255, 0, 0x0000, 255, 255, b'\x01\x00\x00\x00\x00@\x8f\xcd\xabR\x80\x00A,\x80\x00\x00']
2023-05-02 12:57:50.300 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32770, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=48), 255, 0, 0x0000, 255, 255, b'\x01\x00\x00\x00\x00@\x8f\xcd\xabR\x80\x00A,\x80\x00\x00']
2023-05-02 12:57:50.301 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=48, profile_id=0, cluster_id=32770, data=Serialized[b'\x01\x00\x00\x00\x00@\x8f\xcd\xabR\x80\x00A,\x80\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=255, rssi=0)
2023-05-02 12:57:50.302 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model='EZSP' manuf='Silicon Labs' nwk=0x0000 ieee=e0:79:8d:ff:fe:f8:a5:5c is_initialized=False> from ep 0 to ep 0, cluster 32770: b'\x01\x00\x00\x00\x00@\x8f\xcd\xabR\x80\x00A,\x80\x00\x00'
2023-05-02 12:57:50.303 INFO (MainThread) [zigpy.device] [0x0000] Got Node Descriptor: NodeDescriptor(logical_type=<LogicalType.Coordinator: 0>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.AllocateAddress|RxOnWhenIdle|MainsPowered|FullFunctionDevice|AlternatePanCoordinator: 143>, manufacturer_code=43981, maximum_buffer_size=82, maximum_incoming_transfer_size=128, server_mask=11329, maximum_outgoing_transfer_size=128, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=True, *is_coordinator=True, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=False, *is_security_capable=False)
2023-05-02 12:57:50.304 INFO (MainThread) [zigpy.device] [0x0000] Already have endpoints: {0: <zigpy.zdo.ZDO object at 0xd0749340>, 1: <EZSPEndpoint id=1 in=[] out=[] status=<Status.NEW: 0>>}
2023-05-02 12:57:50.304 INFO (MainThread) [zigpy.device] [0x0000] Initializing endpoints [<EZSPEndpoint id=1 in=[] out=[] status=<Status.NEW: 0>>]
2023-05-02 12:57:50.305 INFO (MainThread) [zigpy.endpoint] [0x0000:1] Discovering endpoint information
2023-05-02 12:57:50.305 DEBUG (MainThread) [zigpy.util] Tries remaining: 3
2023-05-02 12:57:50.305 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=3, profile_id=0, cluster_id=<ZDOCmd.Simple_Desc_req: 0x0004>, data=Serialized[b'\x03\x00\x00\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-05-02 12:57:50.306 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x0000, EmberApsFrame(profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=3), 4, b'\x03\x00\x00\x01')
2023-05-02 12:57:50.318 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 49]
2023-05-02 12:57:50.325 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=49), 255, 0, 0x0000, 255, 255, b'\x03\x00\x00\x01']
2023-05-02 12:57:50.325 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=49), 255, 0, 0x0000, 255, 255, b'\x03\x00\x00\x01']
2023-05-02 12:57:50.326 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=49, profile_id=0, cluster_id=4, data=Serialized[b'\x03\x00\x00\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=255, rssi=0)
2023-05-02 12:57:50.326 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model='EZSP' manuf='Silicon Labs' nwk=0x0000 ieee=e0:79:8d:ff:fe:f8:a5:5c is_initialized=False> from ep 0 to ep 0, cluster 4: b'\x03\x00\x00\x01'
2023-05-02 12:57:50.327 DEBUG (MainThread) [zigpy.zdo] [0x0000:zdo] ZDO request ZDOCmd.Simple_Desc_req: [0x0000, 1]
2023-05-02 12:57:50.327 DEBUG (MainThread) [zigpy.zdo] [0x0000:zdo] No handler for ZDO request:ZDOCmd.Simple_Desc_req([0x0000, 1])
2023-05-02 12:57:50.331 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0, EmberApsFrame(profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=49), 4, <EmberStatus.SUCCESS: 0>, b'']
2023-05-02 12:57:50.331 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0, EmberApsFrame(profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=49), 4, <EmberStatus.SUCCESS: 0>, b'']
2023-05-02 12:57:50.343 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32772, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=50), 255, 0, 0x0000, 255, 255, b'\x03\x00\x00\x00\x1a\x01\x04\x01\x00\x04\x00\x05\x00\x00\x06\x00\n\x00\x19\x00\x01\x05\x04\x01\x00 \x00\x00\x05\x02\x05']
2023-05-02 12:57:50.344 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=0, clusterId=32772, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=50), 255, 0, 0x0000, 255, 255, b'\x03\x00\x00\x00\x1a\x01\x04\x01\x00\x04\x00\x05\x00\x00\x06\x00\n\x00\x19\x00\x01\x05\x04\x01\x00 \x00\x00\x05\x02\x05']
2023-05-02 12:57:50.344 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=50, profile_id=0, cluster_id=32772, data=Serialized[b'\x03\x00\x00\x00\x1a\x01\x04\x01\x00\x04\x00\x05\x00\x00\x06\x00\n\x00\x19\x00\x01\x05\x04\x01\x00 \x00\x00\x05\x02\x05'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=255, rssi=0)
2023-05-02 12:57:50.345 DEBUG (MainThread) [zigpy.application] Received frame on uninitialized device <Device model='EZSP' manuf='Silicon Labs' nwk=0x0000 ieee=e0:79:8d:ff:fe:f8:a5:5c is_initialized=False> from ep 0 to ep 0, cluster 32772: b'\x03\x00\x00\x00\x1a\x01\x04\x01\x00\x04\x00\x05\x00\x00\x06\x00\n\x00\x19\x00\x01\x05\x04\x01\x00 \x00\x00\x05\x02\x05'
2023-05-02 12:57:50.347 INFO (MainThread) [zigpy.endpoint] [0x0000:1] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=1, profile=260, device_type=1024, device_version=0, input_clusters=[0, 6, 10, 25, 1281], output_clusters=[1, 32, 1280, 1282])
2023-05-02 12:57:50.348 INFO (MainThread) [zigpy.device] [0x0000] Already have model and manufacturer info
2023-05-02 12:57:50.348 INFO (MainThread) [zigpy.device] [0x0000] Discovered basic device information for <Device model='EZSP' manuf='Silicon Labs' nwk=0x0000 ieee=e0:79:8d:ff:fe:f8:a5:5c is_initialized=True>
2023-05-02 12:57:50.348 DEBUG (MainThread) [zigpy.application] Device is initialized <Device model='EZSP' manuf='Silicon Labs' nwk=0x0000 ieee=e0:79:8d:ff:fe:f8:a5:5c is_initialized=True>
2023-05-02 12:57:50.350 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for Silicon Labs EZSP (e0:79:8d:ff:fe:f8:a5:5c)
2023-05-02 12:57:50.350 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.opple_switch.XiaomiOpple2ButtonSwitchFace2'>
2023-05-02 12:57:50.350 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2, 242} {1}
2023-05-02 12:57:50.350 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.opple_switch.XiaomiOpple2ButtonSwitchFace1'>
2023-05-02 12:57:50.350 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2, 41, 42, 242, 51, 21, 31} {1}
2023-05-02 12:57:50.351 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
2023-05-02 12:57:50.351 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1}
2023-05-02 12:57:50.351 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
2023-05-02 12:57:50.351 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1}
2023-05-02 12:57:50.351 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.tuya.ts0201.MoesTemperatureHumidtySensorWithScreen'>
2023-05-02 12:57:50.351 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2023-05-02 12:57:50.351 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
2023-05-02 12:57:50.352 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2023-05-02 12:57:50.352 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
2023-05-02 12:57:50.352 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2023-05-02 12:57:50.352 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
2023-05-02 12:57:50.352 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint
2023-05-02 12:57:50.352 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
2023-05-02 12:57:50.352 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1}
2023-05-02 12:57:50.354 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getConfigurationValue: (<EzspConfigId.CONFIG_MULTICAST_TABLE_SIZE: 6>,)
2023-05-02 12:57:50.364 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getConfigurationValue: [<EzspStatus.SUCCESS: 0>, 16]
2023-05-02 12:57:50.365 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (0,)
2023-05-02 12:57:50.374 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.375 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (1,)
2023-05-02 12:57:50.388 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.389 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (2,)
2023-05-02 12:57:50.397 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.398 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (3,)
2023-05-02 12:57:50.407 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.408 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (4,)
2023-05-02 12:57:50.416 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.417 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (5,)
2023-05-02 12:57:50.426 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.427 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (6,)
2023-05-02 12:57:50.437 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.438 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (7,)
2023-05-02 12:57:50.445 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.446 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (8,)
2023-05-02 12:57:50.455 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.456 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (9,)
2023-05-02 12:57:50.464 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.465 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (10,)
2023-05-02 12:57:50.475 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.476 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (11,)
2023-05-02 12:57:50.484 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.485 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (12,)
2023-05-02 12:57:50.492 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.494 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (13,)
2023-05-02 12:57:50.504 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.505 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (14,)
2023-05-02 12:57:50.512 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.513 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getMulticastTableEntry: (15,)
2023-05-02 12:57:50.520 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received getMulticastTableEntry: [<EmberStatus.SUCCESS: 0>, EmberMulticastTableEntry(multicastId=0x0000, endpoint=0, networkIndex=0)]
2023-05-02 12:57:50.522 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setMulticastTableEntry: (0, EmberMulticastTableEntry(multicastId=0x0000, endpoint=1, networkIndex=0))
2023-05-02 12:57:50.531 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setMulticastTableEntry: [<EmberStatus.SUCCESS: 0>]
2023-05-02 12:57:50.533 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=5, profile_id=0, cluster_id=<ZDOCmd.Mgmt_Permit_Joining_req: 0x0036>, data=Serialized[b'\x05\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-05-02 12:57:50.533 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendBroadcast: (0xfffc, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=5), 0, 6, b'\x05\x00\x00')
2023-05-02 12:57:50.535 DEBUG (MainThread) [bellows.ezsp.protocol] Send command addTransientLinkKey: (ff:ff:ff:ff:ff:ff:ff:ff, [90, 105, 103, 66, 101, 101, 65, 108, 108, 105, 97, 110, 99, 101, 48, 57])
2023-05-02 12:57:50.544 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received sendBroadcast: [<EmberStatus.SUCCESS: 0>, 51]
2023-05-02 12:57:50.545 DEBUG (MainThread) [bellows.ezsp.protocol] Send command permitJoining: (0,)
2023-05-02 12:57:50.551 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_BROADCAST_LOOPBACK: 5>, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=51), 255, 0, 0x0000, 255, 255, b'\x05\x00\x00']
2023-05-02 12:57:50.552 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST_LOOPBACK: 5>, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=51), 255, 0, 0x0000, 255, 255, b'\x05\x00\x00']
2023-05-02 12:57:50.552 DEBUG (MainThread) [bellows.zigbee.application] Ignoring message type: <EmberIncomingMessageType.INCOMING_BROADCAST_LOOPBACK: 5>
2023-05-02 12:57:50.556 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received addTransientLinkKey: [<EmberStatus.SUCCESS: 0>]
2023-05-02 12:57:50.557 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.TRUST_CENTER_POLICY: 0>, <EzspDecisionBitmask.ALLOW_UNSECURED_REJOINS|ALLOW_JOINS: 3>)
2023-05-02 12:57:50.562 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received permitJoining: [<EmberStatus.SUCCESS: 0>]
2023-05-02 12:57:50.564 DEBUG (MainThread) [bellows.ezsp.protocol] Send command startScan: (<EzspNetworkScanType.ENERGY_SCAN: 0>, <Channels.ALL_CHANNELS: 134215680>, 4)
2023-05-02 12:57:50.569 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setPolicy: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:50.576 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received startScan: [<EmberStatus.SUCCESS: 0>]
2023-05-02 12:57:50.925 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [11, -25]
2023-05-02 12:57:50.925 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [11, -25]
2023-05-02 12:57:51.270 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [12, -15]
2023-05-02 12:57:51.270 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [12, -15]
2023-05-02 12:57:51.618 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [13, -17]
2023-05-02 12:57:51.618 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [13, -17]
2023-05-02 12:57:51.960 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [14, -43]
2023-05-02 12:57:51.961 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [14, -43]
2023-05-02 12:57:52.306 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [15, -20]
2023-05-02 12:57:52.306 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [15, -20]
2023-05-02 12:57:52.570 DEBUG (MainThread) [bellows.ezsp.protocol] Send command setPolicy: (<EzspPolicyId.TRUST_CENTER_POLICY: 0>, <EzspDecisionId.ALLOW_PRECONFIGURED_KEY_JOINS: 1>)
2023-05-02 12:57:52.579 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received setPolicy: [<EzspStatus.SUCCESS: 0>]
2023-05-02 12:57:52.650 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [16, -61]
2023-05-02 12:57:52.650 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [16, -61]
2023-05-02 12:57:52.996 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [17, -56]
2023-05-02 12:57:52.996 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [17, -56]
2023-05-02 12:57:53.341 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [18, -57]
2023-05-02 12:57:53.341 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [18, -57]
2023-05-02 12:57:53.641 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65532, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=51), 6, <EmberStatus.SUCCESS: 0>, b'']
2023-05-02 12:57:53.641 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_BROADCAST: 6>, 65532, EmberApsFrame(profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=51), 6, <EmberStatus.SUCCESS: 0>, b'']
2023-05-02 12:57:53.641 DEBUG (MainThread) [bellows.zigbee.application] Unexpected message send notification tag: 6
2023-05-02 12:57:53.686 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [19, -70]
2023-05-02 12:57:53.686 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [19, -70]
2023-05-02 12:57:54.032 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [20, -70]
2023-05-02 12:57:54.032 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [20, -70]
2023-05-02 12:57:54.377 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [21, -71]
2023-05-02 12:57:54.377 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [21, -71]
2023-05-02 12:57:54.722 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [22, -72]
2023-05-02 12:57:54.723 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [22, -72]
2023-05-02 12:57:55.067 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [23, -72]
2023-05-02 12:57:55.068 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [23, -72]
2023-05-02 12:57:55.413 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [24, -64]
2023-05-02 12:57:55.413 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [24, -64]
2023-05-02 12:57:55.758 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [25, -73]
2023-05-02 12:57:55.758 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [25, -73]
2023-05-02 12:57:56.104 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received energyScanResultHandler: [26, -29]
2023-05-02 12:57:56.104 DEBUG (MainThread) [bellows.zigbee.application] Received energyScanResultHandler frame with [26, -29]
2023-05-02 12:57:56.106 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received scanCompleteHandler: [0, <EmberStatus.SUCCESS: 0>]
2023-05-02 12:57:56.106 DEBUG (MainThread) [bellows.zigbee.application] Received scanCompleteHandler frame with [0, <EmberStatus.SUCCESS: 0>]
2023-05-02 12:57:56.108 DEBUG (MainThread) [zigpy.application] Startup energy scan: {11: 248.35179904154836, 12: 253.15312587790245, 13: 252.6098734923533, 14: 199.54639324360974, 15: 251.4855413631594, 16: 65.63827931994486, 17: 101.75316454653725, 18: 93.91749518109923, 19: 24.768782664129375, 20: 24.768782664129375, 21: 22.00997262297472, 22: 19.532376537906295, 23: 19.532376537906295, 24: 48.47002474921316, 25: 17.31295187283794, 26: 244.0129080387192}
2023-05-02 12:57:56.109 WARNING (MainThread) [zigpy.application] Zigbee channel 15 utilization is 98.62%!
2023-05-02 12:57:56.114 WARNING (MainThread) [zigpy.application] If you are having problems joining new devices, are missing sensor updates, or have issues keeping devices joined, ensure your coordinator is away from interference sources such as USB 3.0 devices, SSDs, WiFi routers, etc.
2023-05-02 12:57:56.117 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 0 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.BasicClusterHandler'>
2023-05-02 12:57:56.117 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 6 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.OnOffClusterHandler'>
2023-05-02 12:57:56.117 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 10 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Time'>
2023-05-02 12:57:56.118 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 25 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Ota'>
2023-05-02 12:57:56.118 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 1281 class: <class 'homeassistant.components.zha.core.cluster_handlers.security.IasAce'>
2023-05-02 12:57:56.118 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x0000](Silicon Labs EZSP) restored as 'available', last seen: 0:00:06 ago, consider_unavailable_time: 7200 seconds
2023-05-02 12:57:56.119 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 0 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.BasicClusterHandler'>
2023-05-02 12:57:56.119 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 2 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.DeviceTemperature'>
2023-05-02 12:57:56.119 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 3 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Identify'>
2023-05-02 12:57:56.119 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 4 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Groups'>
2023-05-02 12:57:56.120 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 5 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Scenes'>
2023-05-02 12:57:56.120 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 6 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.OnOffClusterHandler'>
2023-05-02 12:57:56.120 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 8 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.LevelControlClusterHandler'>
2023-05-02 12:57:56.120 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 9 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Alarms'>
2023-05-02 12:57:56.120 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 768 class: <class 'homeassistant.components.zha.core.cluster_handlers.lighting.ColorClusterHandler'>
2023-05-02 12:57:56.121 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Discovering entities for endpoint: 04:cf:8c:df:3c:75:ff:c7-1
2023-05-02 12:57:56.127 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'button' component -> 'ZHAIdentifyButton' using ['identify']
2023-05-02 12:57:56.127 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'DeviceTemperature' using ['device_temperature']
2023-05-02 12:57:56.127 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'RSSISensor' using ['basic']
2023-05-02 12:57:56.127 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'LQISensor' using ['basic']
2023-05-02 12:57:56.131 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'OnOffTransitionTimeConfigurationEntity' using ['level']
2023-05-02 12:57:56.131 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'OnLevelConfigurationEntity' using ['level']
2023-05-02 12:57:56.132 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'OnTransitionTimeConfigurationEntity' using ['level']
2023-05-02 12:57:56.132 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'OffTransitionTimeConfigurationEntity' using ['level']
2023-05-02 12:57:56.132 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'DefaultMoveRateConfigurationEntity' using ['level']
2023-05-02 12:57:56.132 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'StartUpCurrentLevelConfigurationEntity' using ['level']
2023-05-02 12:57:56.132 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'StartUpColorTemperatureConfigurationEntity' using ['light_color']
2023-05-02 12:57:56.132 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off']
2023-05-02 12:57:56.133 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Discovering entities for endpoint: 04:cf:8c:df:3c:75:ff:c7-242
2023-05-02 12:57:56.140 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x293F](LUMI lumi.light.cwopcn01) restored as 'unavailable', last seen: 2:54:20 ago, consider_unavailable_time: 7200 seconds
2023-05-02 12:57:56.140 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 0 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.BasicClusterHandler'>
2023-05-02 12:57:56.141 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 3 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Identify'>
2023-05-02 12:57:56.141 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 4 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Groups'>
2023-05-02 12:57:56.141 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 5 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Scenes'>
2023-05-02 12:57:56.141 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 6 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.OnOffClusterHandler'>
2023-05-02 12:57:56.141 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 8 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.LevelControlClusterHandler'>
2023-05-02 12:57:56.141 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 768 class: <class 'homeassistant.components.zha.core.cluster_handlers.lighting.ColorClusterHandler'>
2023-05-02 12:57:56.142 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] Discovering entities for endpoint: 00:12:4b:00:1b:4f:f6:fc-11
2023-05-02 12:57:56.147 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'button' component -> 'ZHAIdentifyButton' using ['identify']
2023-05-02 12:57:56.148 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'RSSISensor' using ['basic']
2023-05-02 12:57:56.148 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'sensor' component -> 'LQISensor' using ['basic']
2023-05-02 12:57:56.151 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'OnOffTransitionTimeConfigurationEntity' using ['level']
2023-05-02 12:57:56.152 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'OnLevelConfigurationEntity' using ['level']
2023-05-02 12:57:56.152 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'OnTransitionTimeConfigurationEntity' using ['level']
2023-05-02 12:57:56.152 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'OffTransitionTimeConfigurationEntity' using ['level']
2023-05-02 12:57:56.152 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'DefaultMoveRateConfigurationEntity' using ['level']
2023-05-02 12:57:56.152 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'StartUpCurrentLevelConfigurationEntity' using ['level']
2023-05-02 12:57:56.152 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'number' component -> 'StartUpColorTemperatureConfigurationEntity' using ['light_color']
2023-05-02 12:57:56.152 DEBUG (MainThread) [homeassistant.components.zha.core.discovery] 'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off']
2023-05-02 12:57:56.153 DEBUG (MainThread) [homeassistant.components.zha.core.gateway] [0x426F](GLEDOPTO GL-B-008Z) restored as 'available', last seen: 1:16:01 ago, consider_unavailable_time: 7200 seconds
2023-05-02 12:57:56.154 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 0 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.BasicClusterHandler'>
2023-05-02 12:57:56.154 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 4 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Groups'>
2023-05-02 12:57:56.154 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 5 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Scenes'>
2023-05-02 12:57:56.154 INFO (MainThread) [homeassistant.components.zha.core.endpoint] Creating cluster handler for cluster id: 6 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.OnOffClusterHandler'>
2023-05-02 12:57:56.154 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry SONOFF Zigbee 3.0 USB Dongle Plus V2, s/n: 20221202181808 - ITEAD for zha
Traceback (most recent call last):
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/config_entries.py", line 387, in async_setup
result = await component.async_setup_entry(hass, self)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/__init__.py", line 122, in async_setup_entry
await zha_gateway.async_initialize()
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/gateway.py", line 230, in async_initialize
self.async_load_devices()
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/gateway.py", line 238, in async_load_devices
zha_device = self._async_get_or_create_device(zigpy_device, restored=True)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/gateway.py", line 570, in _async_get_or_create_device
zha_device = ZHADevice.new(self._hass, zigpy_device, self, restored)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/device.py", line 408, in new
zha_dev = cls(hass, zigpy_dev, gateway)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/device.py", line 153, in __init__
self._endpoints[ep_id] = Endpoint.new(endpoint, self)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/endpoint.py", line 109, in new
endpoint.add_all_cluster_handlers()
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/endpoint.py", line 140, in add_all_cluster_handlers
cluster_handler = cluster_handler_class(cluster, self)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/cluster_handlers/general.py", line 358, in __init__
super().__init__(cluster, endpoint)
File "/srv/homeassistant/lib/python3.10/site-packages/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 133, in __init__
attr_def: ZCLAttributeDef = self.cluster.attributes_by_name[
KeyError: 'on_off'
2023-05-02 12:57:56.169 DEBUG (MainThread) [bellows.ezsp.protocol] Send command networkState: ()
2023-05-02 12:57:56.173 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=zha>
2023-05-02 12:57:56.185 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame received networkState: [<EmberNetworkStatus.JOINED_NETWORK: 2>]
2023-05-02 12:57:56.187 DEBUG (MainThread) [bellows.ezsp.protocol] Send command getNetworkParameters: ()
2023-05-02 12:57:56.188 INFO (MainThread) [homeassistant.setup] Setting up automation
Is this enough or do you need also the earlier logs?
Are you using any custom quirks or modified zha-quirks versions?
No nothing special, I switched a few times between zigbee2mqtt, deconz and zha, but I don't remember I modified something for zha and I can't find anything in configuration.yml
(homeassistant) homeassistant@raspberrypi:~/.homeassistant $ grep zha configuration.yaml
homeassistant.components.zha: debug
zhaquirks: debug
Huh, that's weird then. Some device/quirk causes this issue, but the debug logs do not contain which device crashes the initialization.
Can you send your zigbee.db file to [email protected]?
Combined with the debug logs you posted above, it should be possible to get an idea of what device is causing this for you.