search

zigpy / zigpy-cc

Texas Instruments Z-Stack ZNP handler for zigpy
https://github.com/zigpy/zigpy-cc
GNU General Public License v3.0
71 stars 13 forks source link

Waiter Timeout Errors #65

Open danieledwardgeorgehitchcock opened 4 years ago

danieledwardgeorgehitchcock commented 4 years ago

I am using Zigpy via the ZHA component in Home Assistant. I have set it up with my CC2531 USB stick running the latest Koenkk v1.2 source routing coordinator firmware.

Throughout the duration of the service being live, I am constantly getting error messages such as the below:

Waiter timeout: <Waiter matcher=<Matcher type=CommandType.AREQ subsystem=Subsystem.AF command=dataConfirm payload={'endpoint': 1, 'transid': 159}> future=<Future cancelled> timeout=10000 sequence=None>

These are coming from various endpoints - the one above is a Sonoff Basic ZB R3 which is located around 3 meters away from my coordinator.

At present, I have 12 devices on my network. 4 of them have routing capabilities (2 Sononff Basic ZB R3 and 2 CC2531 Router Firmwares).

What could be causing these timeouts, given that the endpoint device is in such close proximity to my coordinator, and mains powered?

Adminiuga commented 4 years ago

Please enable debug logging and submit the debug logs to zigpy-cc repository with this issue.

danieledwardgeorgehitchcock commented 4 years ago

I am limited by the amount of characters I can post but when starting Home Assistant, I get this (hopefully there's nothing sensitive):

2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] Loading application state from /config/zigbee.db 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x228a:1:0x0000] Attribute id: 4 value: SONOFF 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x228a:1:0x0000] Attribute id: 5 value: BASICZBR3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0000] Attribute id: 5 value: lumi.sensor_cube.aqgl01 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0000] Attribute id: 5 value: lumi.vibration.aq1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xa050:1:0x0000] Attribute id: 4 value: SONOFF 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xa050:1:0x0000] Attribute id: 5 value: BASICZBR3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0000] Attribute id: 5 value: lumi.weather 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0000] Attribute id: 5 value: lumi.weather 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0000] Attribute id: 4 value: IKEA of Sweden 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0000] Attribute id: 5 value: TRADFRI wireless dimmer 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0000] Attribute id: 5 value: lumi.sensor_switch.aq3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0000] Attribute id: 5 value: lumi.remote.b1acn01 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xbae0:8:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xbae0:8:0x0000] Attribute id: 5 value: lumi.router 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x444e:8:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x444e:8:0x0000] Attribute id: 5 value: lumi.router 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for SONOFF BASICZBR3 (00:12:4b:00:1e:73:28:a5) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {3} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_cube.aqgl01 (00:15:8d:00:02:9b:a0:6a) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.cube_aqgl01.CubeAQGL01'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:02:9b:a0:6a: <class 'zhaquirks.xiaomi.aqara.cube_aqgl01.CubeAQGL01'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.vibration.aq1 (00:15:8d:00:03:13:a0:af) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.vibration_aq1.VibrationAQ1'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:03:13:a0:af: <class 'zhaquirks.xiaomi.aqara.vibration_aq1.VibrationAQ1'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for SONOFF BASICZBR3 (00:12:4b:00:1e:72:86:31) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {3} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.weather (00:15:8d:00:03:fa:a8:5c) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.weather.Weather'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:03:fa:a8:5c: <class 'zhaquirks.xiaomi.aqara.weather.Weather'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.weather (00:15:8d:00:03:cd:1c:f1) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.weather.Weather'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:03:cd:1c:f1: <class 'zhaquirks.xiaomi.aqara.weather.Weather'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for IKEA of Sweden TRADFRI wireless dimmer (00:0b:57:ff:fe:2e:dc:aa) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.ikea.tradfriplug.TradfriPlug'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2, 242} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because profile_id mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {3} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {1} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because device_type mismatch on at least one endpoint 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.remote.b1acn01 (00:15:8d:00:04:01:85:05) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.sensor_switch_aq3.SwitchAQ3B'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:04:01:85:05: <class 'zhaquirks.xiaomi.aqara.sensor_switch_aq3.SwitchAQ3B'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_switch.aq3 (00:15:8d:00:02:b0:55:43) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.sensor_switch_aq3.SwitchAQ3'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:02:b0:55:43: <class 'zhaquirks.xiaomi.aqara.sensor_switch_aq3.SwitchAQ3'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.sensor_magnet.aq2 (00:15:8d:00:04:5c:ed:84) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Found custom device replacement for 00:15:8d:00:04:5c:ed:84: <class 'zhaquirks.xiaomi.aqara.magnet_aq2.MagnetAQ2'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.router (00:12:4b:00:18:e2:50:71) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {3} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Checking quirks for LUMI lumi.router (00:12:4b:00:18:e2:12:62) 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'bellows.zigbee.application.EZSPCoordinator'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {11, 13} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.lutron.lzl4bwhl01remote.LutronLZL4BWHL01Remote2'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.osram.a19twhite.A19TunableWhite'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {3} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rom001.PhilipsROM001'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl020.PhilipsRWL020'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.philips.rwl021.PhilipsRWL021'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1, 2} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {232, 230} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Considering <class 'zhaquirks.xiaomi.mija.smoke.MijiaHoneywellSmokeDetectorSensor'> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.quirks.registry] Fail because endpoint list mismatch: {1} {8} 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x228a:1:0x0000] Attribute id: 4 value: SONOFF 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x228a:1:0x0000] Attribute id: 5 value: BASICZBR3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0000] Attribute id: 5 value: lumi.sensor_cube.aqgl01 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0500] Attribute id: 1 value: 45 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0000] Attribute id: 5 value: lumi.vibration.aq1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xa050:1:0x0000] Attribute id: 4 value: SONOFF 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xa050:1:0x0000] Attribute id: 5 value: BASICZBR3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0000] Attribute id: 5 value: lumi.weather 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0000] Attribute id: 5 value: lumi.weather 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:3:0x000c] Attribute id: 65285 value: 500 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:3:0x000c] Attribute id: 85 value: 94.57001495361328 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:3:0x000c] Attribute id: 0 value: 94.57001495361328 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0000] Attribute id: 4 value: IKEA of Sweden 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0000] Attribute id: 5 value: TRADFRI wireless dimmer 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0001] Attribute id: 49 value: 5 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0001] Attribute id: 51 value: 2 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0000] Attribute id: 7 value: 3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0001] Attribute id: 32 value: 0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x31a5:1:0x0001] Attribute id: 33 value: 11 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0000] Attribute id: 7 value: 3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0000] Attribute id: 5 value: lumi.sensor_switch.aq3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0000] Attribute id: 5 value: lumi.sensor_magnet.aq2 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0000] Attribute id: 5 value: lumi.remote.b1acn01 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0012] Attribute id: 85 value: 1.0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0012] Attribute id: 0 value: single 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:2:0x0012] Attribute id: 85 value: 2.0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:2:0x0012] Attribute id: 0 value: None 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0101] Attribute id: 1283 value: 42 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0101] Attribute id: 1288 value: 1000796913650 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xbae0:8:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xbae0:8:0x0000] Attribute id: 5 value: lumi.router 2020-08-12 14:10:51 INFO (SyncWorker_2) [googleapiclient.discovery] URL being requested: GET https://www.googleapis.com/calendar/v3/users/me/calendarList?alt=json 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x444e:8:0x0000] Attribute id: 4 value: LUMI 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x444e:8:0x0000] Attribute id: 5 value: lumi.router 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0012] Attribute id: 85 value: 18.0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0012] Attribute id: 0 value: shake 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0001] Attribute id: 49 value: 10 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0001] Attribute id: 51 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0500] Attribute id: 2 value: 0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0500] Attribute id: 0 value: 0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0001] Attribute id: 49 value: 11 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0001] Attribute id: 51 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0000] Attribute id: 7 value: 3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0001] Attribute id: 49 value: 10 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0001] Attribute id: 51 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0000] Attribute id: 7 value: 3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0000] Attribute id: 7 value: 3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0000] Attribute id: 7 value: 3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0001] Attribute id: 49 value: 10 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0001] Attribute id: 51 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0000] Attribute id: 7 value: 3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0001] Attribute id: 49 value: 10 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0001] Attribute id: 51 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0001] Attribute id: 49 value: 9 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0001] Attribute id: 51 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0000] Attribute id: 7 value: 3 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0001] Attribute id: 49 value: 10 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0001] Attribute id: 51 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xa050:1:0x0000] Attribute id: 7 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x228a:1:0x0000] Attribute id: 7 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x444e:8:0x0000] Attribute id: 7 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xbae0:8:0x0000] Attribute id: 7 value: 1 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0000] Attribute id: 65281 value: b'\x01!\r\x0c\x03(#\x04!\xa8\x13\x05!\x0e\x00\x06$\x01\x00\x00\x00\x00\n!\x8a"d\x10\x00' 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0001] Attribute id: 33 value: 200 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfc7d:1:0x0001] Attribute id: 32 value: 30 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0101] Attribute id: 85 value: 1.0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0000] Attribute id: 65281 value: b'\x01!\xd1\x0b\x03(\x1e\x04!\xa8\x13\x05!0\x00\x06$\x06\x00\x00\x00\x00\x08!\x08\x03\n!\x00\x00\x98!\x14\x00\x99!\xca\x03\x9a%\xf2\xff#\x04\xe2\x00' 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0001] Attribute id: 33 value: 200 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0001] Attribute id: 32 value: 30 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0101] Attribute id: 1285 value: 196608 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x49c3:1:0x0101] Attribute id: 0 value: Vibration 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0000] Attribute id: 65281 value: b'\x01!\xc7\x0b\x03(#\x04!\xa8\x13\x05!\r\x00\x06$\x01\x00\x00\x00\x00\n!\x8a"' 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0001] Attribute id: 33 value: 200 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x2af4:1:0x0001] Attribute id: 32 value: 30 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0000] Attribute id: 65281 value: b'\x01!\xbd\x0b\x04!\xa8C\x05!\r\x00\x06$\x01\x00\x00\x00\x00d)\x12\ne!\xd0\x18f+\xa3\x88\x01\x00\n!\x8a"' 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0001] Attribute id: 33 value: 200 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0001] Attribute id: 32 value: 30 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0402] Attribute id: 0 value: 2582 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0405] Attribute id: 0 value: 6341 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x3f73:1:0x0403] Attribute id: 0 value: 1005 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0000] Attribute id: 65281 value: b'\x01!\x03\x0c\x03("\x04!\xa8\x13\x05!]?\x06$\x01\x00\x00\x00\x00\x08!\x05\x01\n!\x8a"\x98!b\x00\x99!\x00\x00' 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0001] Attribute id: 33 value: 200 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x6abc:1:0x0001] Attribute id: 32 value: 30 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0000] Attribute id: 65281 value: b'\x01!\xa9\x0b\x04!\xa8\x13\x05!\x14\x00\x06$\x01\x00\x00\x00\x00d)y\x0be! \x13f+\xd8\x87\x01\x00\n!P\xa0' 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0001] Attribute id: 33 value: 185 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0001] Attribute id: 32 value: 29 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0402] Attribute id: 0 value: 2937 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0405] Attribute id: 0 value: 4896 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xfaa8:1:0x0403] Attribute id: 0 value: 1003.12 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0000] Attribute id: 65281 value: b'\x01!\xbd\x0b\x03(\x1f\x04!\xa8C\x05!\x9a\x00\x06$\x01\x00\x00\x00\x00\n!\x00\x00\x97!\x00\x00\x98!8\x01\x99!"\x01\x9a!\x04\x00' 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0001] Attribute id: 33 value: 200 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xc35b:1:0x0001] Attribute id: 32 value: 30 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x228a:1:0x0006] Attribute id: 0 value: 0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xa050:1:0x0006] Attribute id: 0 value: 0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0x444e:8:0x0006] Attribute id: 0 value: 0 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy.appdb] [0xbae0:8:0x0006] Attribute id: 0 value: 0 2020-08-12 14:10:51 INFO (MainThread) [zigpy_cc.zigbee.application] Starting zigpy-cc version: 0.4.4 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy_cc.uart] Connecting on port /dev/serial/by-id/usb-Texas_Instruments_TI_CC2531_USB_CDC___0X00124B0014B93FC5-if00 with boudrate 115200

Then I get this further down the log:

2020-08-12 14:10:51 DEBUG (MainThread) [zigpy_cc.uart] Connection made 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x06\x00ND\x08\x01\x00"\x00{\x9a\xe4\x00\x00\x07\x00(\n\x00\x00 \x00P\xa0\x1b' length=27 fcs=18> 2020-08-12 14:10:51 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 6, 'srcaddr': 0x444e, 'srcendpoint': 8, 'dstendpoint': 1, 'wasbroadcast': 0, 'linkquality': 34, 'securityuse': 0, 'timestamp': 14981755, 'transseqnumber': 0, 'len': 7, 'data': b'\x00(\n\x00\x00 \x00'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.SYS command_id=2 data=b'\x02\x00\x02\x06\x03\x9b\x154\x01\x02\x00\x00\x00\x00' length=14 fcs=209> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP SYS version tsn: None {'transportrev': 2, 'product': 0, 'majorrel': 2, 'minorrel': 6, 'maintrel': 3, 'revision': 20190619} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] Version response: {'transportrev': 2, 'product': 0, 'majorrel': 2, 'minorrel': 6, 'maintrel': 3, 'revision': 20190619} 2020-08-12 14:10:53 INFO (MainThread) [zigpy_cc.zigbee.application] Detected znp version 'zStack12' ({'transportrev': 2, 'product': 0, 'majorrel': 2, 'minorrel': 6, 'maintrel': 3, 'revision': 20190619}) 2020-08-12 14:10:53 INFO (MainThread) [zigpy_cc.zigbee.application] Forming network 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ SYS osalNvRead tsn: None {'id': <NvItemsIds.ZNP_HAS_CONFIGURED_ZSTACK1: 3840>, 'offset': 0, 'len': 1, 'value': b'U'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x03!\x08\x00\x0f\x00%' 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.SYS command_id=8 data=b'\x00\x01\x00' length=3 fcs=107> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP SYS osalNvRead tsn: None {'status': 0, 'len': 1, 'value': b'\x00'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Item 'networkKeyDistribute' is valid 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ SAPI readConfiguration tsn: None {'id': <NvItemsIds.PRECFGKEY: 98>, 'configid': <NvItemsIds.PRECFGKEY: 98>, 'len': 16, 'offset': 0, 'value': b'\x01\x03\x05\x07\t\x0b\r\x0f\x00\x02\x04\x06\x08\n\x0c\r'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x01&\x04bA' 2020-08-12 14:10:53 INFO (MainThread) [homeassistant.components.withings] Updating all withings data 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.SAPI command_id=4 data=b'\x00b\x10\x01\x03\x05\x07\t\x0b\r\x0f\x00\x02\x04\x06\x08\n\x0c\r' length=19 fcs=0> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP SAPI readConfiguration tsn: None {'status': 0, 'configid': 98, 'len': 16, 'value': b'\x01\x03\x05\x07\t\x0b\r\x0f\x00\x02\x04\x06\x08\n\x0c\r'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Item 'networkKey' is valid 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ SYS osalNvRead tsn: None {'id': <NvItemsIds.PANID: 131>, 'len': 2, 'offset': 0, 'value': b'b\x1a'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x03!\x08\x83\x00\x00\xa9' 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.SYS command_id=8 data=b'\x00\x02b\x1a' length=4 fcs=23> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP SYS osalNvRead tsn: None {'status': 0, 'len': 2, 'value': b'b\x1a'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Item 'panID' is valid 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ SYS osalNvRead tsn: None {'id': <NvItemsIds.EXTENDED_PAN_ID: 45>, 'len': 8, 'offset': 0, 'value': b'\xdd\xdd\xdd\xdd\xdd\xdd\xdd\xdd'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x03!\x08-\x00\x00\x07' 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.SYS command_id=8 data=b'\x00\x08\xdd\xdd\xdd\xdd\xdd\xdd\xdd\xdd' length=10 fcs=107> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP SYS osalNvRead tsn: None {'status': 0, 'len': 8, 'value': b'\xdd\xdd\xdd\xdd\xdd\xdd\xdd\xdd'} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Item 'extendedPanID' is valid 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL getDeviceInfo tsn: None {} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x00'\x00'" 2020-08-12 14:10:53 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.kitchen_soundtouch, old_state=None, new_state=<state media_player.kitchen_soundtouch=off; source_list=['AUX', 'BLUETOOTH'], friendly_name=Kitchen SoundTouch, supported_features=20413 @ 2020-08-12T14:10:53.587944+01:00>> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=0 data=b'\x00\xc5?\xb9\x14\x00K\x12\x00\x00\x00\x07\t\x05\xc3I~\xc8P\xa0\x8a"[\xc3' length=24 fcs=134> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL getDeviceInfo tsn: None {'status': 0, 'ieeeaddr': 00:12:4b:00:14:b9:3f:c5, 'shortaddr': 0x0000, 'devicetype': 7, 'devicestate': 9, 'numassocdevices': 5, 'assocdeviceslist': [18883, 51326, 41040, 8842, 50011]} 2020-08-12 14:10:53 INFO (MainThread) [zigpy_cc.api] Device info: {'status': 0, 'ieeeaddr': 00:12:4b:00:14:b9:3f:c5, 'shortaddr': 0x0000, 'devicetype': 7, 'devicestate': 9, 'numassocdevices': 5, 'assocdeviceslist': [18883, 51326, 41040, 8842, 50011]} 2020-08-12 14:10:53 INFO (MainThread) [zigpy_cc.zigbee.start_znp] ZNP is already started as coordinator 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Register endpoints... 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO activeEpReq tsn: None {'dstaddr': 0, 'nwkaddrofinterest': 0} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x04%\x05\x00\x00\x00\x00$' 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=5 data=b'\x00' length=1 fcs=97> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO activeEpReq tsn: None {'status': 0} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.ZDO command_id=133 data=b'\x00\x00\x00\x00\x00\r\xf2/\r\x0cn\x0b\x08\x06\x05\x04\x03\x02\x01' length=19 fcs=104> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ ZDO activeEpRsp tsn: None {'srcaddr': 0x0000, 'status': 0, 'nwkaddr': 0x0000, 'activeepcount': 13, 'activeeplist': [242, 47, 13, 12, 110, 11, 8, 6, 5, 4, 3, 2, 1]} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '1' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '2' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '3' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '4' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '5' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '6' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '8' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '11' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '110' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '12' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '13' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '47' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.start_znp] Endpoint '242' already registered 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ ZDO extFindGroup tsn: None {'endpoint': 242, 'groupid': 2948} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x03%J\xf2\x84\x0b\x11' 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.ZDO command_id=74 data=b'\x00\x84\x0b\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' length=19 fcs=179> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP ZDO extFindGroup tsn: None {'status': 0, 'groupid': 2948, 'namelen': 0, 'groupname': b''} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.zigbee.application] ZNP started, status: resumed 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL getDeviceInfo tsn: None {} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x00'\x00'" 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] --> SREQ UTIL ledControl tsn: None {'ledid': 3, 'mode': <LedMode.Off: 0>} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Send: b"\xfe\x02'\n\x03\x00," 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=0 data=b'\x00\xc5?\xb9\x14\x00K\x12\x00\x00\x00\x07\t\x05\xc3I~\xc8P\xa0\x8a"[\xc3' length=24 fcs=134> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL getDeviceInfo tsn: None {'status': 0, 'ieeeaddr': 00:12:4b:00:14:b9:3f:c5, 'shortaddr': 0x0000, 'devicetype': 7, 'devicestate': 9, 'numassocdevices': 5, 'assocdeviceslist': [18883, 51326, 41040, 8842, 50011]} 2020-08-12 14:10:53 INFO (MainThread) [zigpy_cc.api] Device info: {'status': 0, 'ieeeaddr': 00:12:4b:00:14:b9:3f:c5, 'shortaddr': 0x0000, 'devicetype': 7, 'devicestate': 9, 'numassocdevices': 5, 'assocdeviceslist': [18883, 51326, 41040, 8842, 50011]} 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.UTIL command_id=10 data=b'\x00' length=1 fcs=108> 2020-08-12 14:10:53 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP UTIL ledControl tsn: None {'status': 0}

Then:

2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x06\x00\x8a"\x01/\x00"\x00M;\xe9\x00\x00\x07\x08h\n\x00\x00\x10\x00P\xa0\x1c' length=27 fcs=114> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 6, 'srcaddr': 0x228a, 'srcendpoint': 1, 'dstendpoint': 47, 'wasbroadcast': 0, 'linkquality': 34, 'securityuse': 0, 'timestamp': 15285069, 'transseqnumber': 0, 'len': 7, 'data': b'\x08h\n\x00\x00\x10\x00'} 2020-08-12 14:12:22 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=104 command_id=Command.Report_Attributes> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.false>>]] 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] Attribute report received: on_off=0 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.zigbee.application] request (0x228a, 260, 6, 1, 1, 104, b'\x18h\x0b\n\x00', False, False) 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] --> SREQ AF dataRequest tsn: 104 {'dstaddr': 8842, 'destendpoint': 1, 'srcendpoint': 1, 'clusterid': 6, 'transid': 36, 'options': 0, 'radius': 30, 'len': 5, 'data': b'\x18h\x0b\n\x00'} 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Send: b'\xfe\x0f$\x01\x8a"\x01\x01\x06\x00$\x00\x1e\x05\x18h\x0b\n\x00\xca' 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x06\x00\x8a"\x01\r\x00"\x00M;\xe9\x00\x00\x07\x08h\n\x00\x00\x10\x00P\xa0\x1c' length=27 fcs=80> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 6, 'srcaddr': 0x228a, 'srcendpoint': 1, 'dstendpoint': 13, 'wasbroadcast': 0, 'linkquality': 34, 'securityuse': 0, 'timestamp': 15285069, 'transseqnumber': 0, 'len': 7, 'data': b'\x08h\n\x00\x00\x10\x00'} 2020-08-12 14:12:22 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=104 command_id=Command.Report_Attributes> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.false>>]] 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] Attribute report received: on_off=0 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x06\x00\x8a"\x01n\x00"\x00M;\xe9\x00\x00\x07\x08h\n\x00\x00\x10\x00P\xa0\x1c' length=27 fcs=51> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 6, 'srcaddr': 0x228a, 'srcendpoint': 1, 'dstendpoint': 110, 'wasbroadcast': 0, 'linkquality': 34, 'securityuse': 0, 'timestamp': 15285069, 'transseqnumber': 0, 'len': 7, 'data': b'\x08h\n\x00\x00\x10\x00'} 2020-08-12 14:12:22 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=104 command_id=Command.Report_Attributes> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.false>>]] 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] Attribute report received: on_off=0 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x06\x00\x8a"\x01\x0b\x00"\x00M;\xe9\x00\x00\x07\x08h\n\x00\x00\x10\x00P\xa0\x1c' length=27 fcs=86> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 6, 'srcaddr': 0x228a, 'srcendpoint': 1, 'dstendpoint': 11, 'wasbroadcast': 0, 'linkquality': 34, 'securityuse': 0, 'timestamp': 15285069, 'transseqnumber': 0, 'len': 7, 'data': b'\x08h\n\x00\x00\x10\x00'} 2020-08-12 14:12:22 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=104 command_id=Command.Report_Attributes> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.false>>]] 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] Attribute report received: on_off=0 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x06\x00\x8a"\x01\x08\x00"\x00M;\xe9\x00\x00\x07\x08h\n\x00\x00\x10\x00P\xa0\x1c' length=27 fcs=85> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 6, 'srcaddr': 0x228a, 'srcendpoint': 1, 'dstendpoint': 8, 'wasbroadcast': 0, 'linkquality': 34, 'securityuse': 0, 'timestamp': 15285069, 'transseqnumber': 0, 'len': 7, 'data': b'\x08h\n\x00\x00\x10\x00'} 2020-08-12 14:12:22 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=104 command_id=Command.Report_Attributes> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.false>>]] 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] Attribute report received: on_off=0 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=129 data=b'\x00\x00\x06\x00\x8a"\x01\x01\x00"\x00M;\xe9\x00\x00\x07\x08h\n\x00\x00\x10\x00P\xa0\x1c' length=27 fcs=92> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF incomingMsg tsn: None {'groupid': 0, 'clusterid': 6, 'srcaddr': 0x228a, 'srcendpoint': 1, 'dstendpoint': 1, 'wasbroadcast': 0, 'linkquality': 34, 'securityuse': 0, 'timestamp': 15285069, 'transseqnumber': 0, 'len': 7, 'data': b'\x08h\n\x00\x00\x10\x00'} 2020-08-12 14:12:22 INFO (MainThread) [zigpy_cc.zigbee.application] handle_message incomingMsg 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=False disable_default_response=False> manufacturer=None tsn=104 command_id=Command.Report_Attributes> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] ZCL request 0x000a: [[<Attribute attrid=0 value=<TypeValue type=Bool, value=Bool.false>>]] 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.zcl] [0x228a:1:0x0006] Attribute report received: on_off=0 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.util] Duplicate 104 TSN 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.util] Duplicate 104 TSN 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.util] Duplicate 104 TSN 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.util] Duplicate 104 TSN 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy.util] Duplicate 104 TSN 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.SRSP subsystem=Subsystem.AF command_id=1 data=b'\x00' length=1 fcs=100> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] <-- SRSP AF dataRequest tsn: None {'status': 0} 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.uart] Frame received: <UnpiFrame type=CommandType.AREQ subsystem=Subsystem.AF command_id=128 data=b'\x00\x01$' length=3 fcs=226> 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.api] <-- AREQ AF dataConfirm tsn: None {'status': 0, 'endpoint': 1, 'transid': 36} 2020-08-12 14:12:22 DEBUG (MainThread) [zigpy_cc.zigbee.application] message ignored: dataConfirm

Finally:

2020-08-12 14:12:32 WARNING (MainThread) [zigpy_cc.api] Waiter timeout: <Waiter matcher=<Matcher type=CommandType.AREQ subsystem=Subsystem.AF command=dataConfirm payload={'endpoint': 1, 'transid': 36}> future=<Future cancelled> timeout=10000 sequence=None>