Yoda-x / ha-zha-new

update of the zha component
56 stars 10 forks source link

Sensor states never update #95

Closed andrewlphilpott closed 4 years ago

andrewlphilpott commented 5 years ago

A couple months ago I had an issue where all of my zigbee devices just stopped working and zha_new started throwing some errors: https://github.com/Yoda-x/ha-zha-new/issues/87

In the end I was able to get zha_new running again for the most part and all of my lights started working again. None of my motion or door/window sensors have worked since then, though. I have tried removing them, resetting them, and re-adding them. I'm always able to get them to pair fine, but their states never update. I can tell that the sensors themselves are sensing motion or opening/closing, because they still blink when they should, they just never update. Also their last seen value is always null.

The sensors in question are a Centralite motion sensor, Aqara motion sensor and two Aqara door sensors. I also have two Aqara buttons that haven't worked properly since the issue I referenced above, but I haven't really tried much with those.

andrewlphilpott commented 5 years ago

In case it helps, here's my log with debug turned on for zha_new:

2019-08-08 14:20:05 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for zha_new which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942] device init for <class 'str'>(SoftWhite)(7c:e5:24:00:00:12:53:b6) -> Endpoints: [0, 1], already joined 
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:0] endpoint init
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1] endpoint init
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1] node config for 7c:e5:24:00:00:12:53:b6-1: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] Import DH SoftWhite failed: ("No module named 'custom_components.device.softwhite'",)
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1] pre call _custom_endpoint_init: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1] no call _custom_endpoint_init: SoftWhite
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1] node config for 7c:e5:24:00:00:12:53:b6-1: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1] config reports skipped for 7c:e5:24:00:00:12:53:b6, already joined 
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1] 2:profile 260, component: light cluster:[{768, 4096, 3, 4, 5, 6, 8}, set()]
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1] Return from component general entity:7c:e5:24:00:00:12:53:b6
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xa942] Exit device init 7c:e5:24:00:00:12:53:b6
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9] device init for <class 'str'>(SoftWhite)(7c:e5:24:00:00:0b:9c:1b) -> Endpoints: [0, 1], already joined 
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:0] endpoint init
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1] endpoint init
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1] node config for 7c:e5:24:00:00:0b:9c:1b-1: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1] pre call _custom_endpoint_init: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1] no call _custom_endpoint_init: SoftWhite
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1] node config for 7c:e5:24:00:00:0b:9c:1b-1: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1] config reports skipped for 7c:e5:24:00:00:0b:9c:1b, already joined 
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1] 2:profile 260, component: light cluster:[{768, 4096, 3, 4, 5, 6, 8}, set()]
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1] Return from component general entity:7c:e5:24:00:00:0b:9c:1b
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9] Exit device init 7c:e5:24:00:00:0b:9c:1b
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a] device init for <class 'str'>(3326-L)(00:0d:6f:00:0e:26:f3:4a) -> Endpoints: [0, 1, 2], already joined 
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:0] endpoint init
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] endpoint init
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] node config for 00:0d:6f:00:0e:26:f3:4a-1: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] Import DH 3326-L failed: ("No module named 'custom_components.device.3326-l'",)
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] pre call _custom_endpoint_init: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] no call _custom_endpoint_init: 3326-L
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] node config for 00:0d:6f:00:0e:26:f3:4a-1: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] config reports skipped for 00:0d:6f:00:0e:26:f3:4a, already joined 
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] 2:profile 260, component: binary_sensor cluster:[{0, 1280, 1030, 7}, {768, 1280, 4, 5, 6, 8}]
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] Return from component general entity:00:0d:6f:00:0e:26:f3:4a
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0x912a:1] Call single-cluster entity: 1026
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71] device init for <class 'NoneType'>(None)(00:15:8d:00:02:e9:98:37) -> Endpoints: [0, 1], already joined 
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71:0] endpoint init
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71:1] endpoint init
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71:1] node config for 00:15:8d:00:02:e9:98:37-1: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71:1] node config for 00:15:8d:00:02:e9:98:37-1: {}
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71:1] config reports skipped for 00:15:8d:00:02:e9:98:37, already joined 
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71:1] 2:profile 260, component: binary_sensor cluster:[{0, 1280, 1030, 7}, {768, 1280, 4, 5, 6, 8}]
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71:1] Return from component general entity:00:15:8d:00:02:e9:98:37
2019-08-08 14:20:47 DEBUG (MainThread) [custom_components.zha_new] [0xcf71:1] Call single-cluster entity: 1024
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a] device init for <class 'str'>(SoftWhite)(7c:e5:24:00:00:03:46:53) -> Endpoints: [0, 1], already joined 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:0] endpoint init
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1] endpoint init
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1] node config for 7c:e5:24:00:00:03:46:53-1: {}
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1] pre call _custom_endpoint_init: {}
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1] no call _custom_endpoint_init: SoftWhite
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1] node config for 7c:e5:24:00:00:03:46:53-1: {}
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1] config reports skipped for 7c:e5:24:00:00:03:46:53, already joined 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1] 2:profile 260, component: light cluster:[{768, 4096, 3, 4, 5, 6, 8}, set()]
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1] Return from component general entity:7c:e5:24:00:00:03:46:53
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] [0x378a] Exit device init 7c:e5:24:00:00:03:46:53
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.light] [0x378a:1] initialize cluster listeners: ([4096, 3, 4, 5, 6, 8]/[]) 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.light] [0x378a:1] called to set reports
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.light] [0xa942:1] initialize cluster listeners: ([4096, 3, 4, 5, 6, 8]/[]) 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.light] [0xa942:1] called to set reports
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.light] [0x2cd9:1] initialize cluster listeners: ([4096, 3, 4, 5, 6, 8]/[]) 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.light] [0x2cd9:1] called to set reports
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x912a:1] initialize cluster listeners: -[(0, <zigpy.zcl.clusters.general.Basic object at 0x711666f0>), (1280, <zigpy.zcl.clusters.security.IasZone object at 0x71166830>)]- 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x912a:1] exit make binary-sensor 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] set Entity object: <class 'custom_components.zha_new.binary_sensor.BinarySensor'>-00:0d:6f:00:0e:26:f3:4a_1 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] Return binary_sensor init-cluster {0: <zigpy.zcl.clusters.general.Basic object at 0x711666f0>, 1: <zigpy.zcl.clusters.general.PowerConfiguration object at 0x71166730>, 3: <zigpy.zcl.clusters.general.Identify object at 0x71166770>, 32: <zigpy.zcl.clusters.general.PollControl object at 0x711667b0>, 1026: <zigpy.zcl.clusters.measurement.TemperatureMeasurement object at 0x711667f0>, 1280: <zigpy.zcl.clusters.security.IasZone object at 0x71166830>, 2821: <zigpy.zcl.clusters.homeautomation.Diagnostic object at 0x71166870>}
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0xcf71:1] initialize cluster listeners: -[(0, <zigpy.zcl.clusters.general.Basic object at 0x711669f0>), (1280, <zigpy.zcl.clusters.security.IasZone object at 0x71166af0>), (1030, <zigpy.zcl.clusters.measurement.OccupancySensing object at 0x71166a70>)]- 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0xcf71:1] exit make binary-sensor 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] set Entity object: <class 'custom_components.zha_new.binary_sensor.OccupancySensor'>-00:15:8d:00:02:e9:98:37_1_occupancy 
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] Return binary_sensor init-cluster {0: <zigpy.zcl.clusters.general.Basic object at 0x711669f0>, 65535: <zigpy.zcl.clusters.manufacturer_specific.ManufacturerSpecificCluster object at 0x71166a30>, 1030: <zigpy.zcl.clusters.measurement.OccupancySensing object at 0x71166a70>, 1024: <zigpy.zcl.clusters.measurement.IlluminanceMeasurement object at 0x71166ab0>, 1280: <zigpy.zcl.clusters.security.IasZone object at 0x71166af0>, 1: <zigpy.zcl.clusters.general.PowerConfiguration object at 0x71166b30>, 3: <zigpy.zcl.clusters.general.Identify object at 0x71166b70>}
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] Restore state for light.guest_room_lamp:
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] Restore state for light.dining_room_lamp:
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] Restore state for light.living_room_lamp:
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] Restore state for binary_sensor.centralite_3326_l_0e26f34a_1:
2019-08-08 14:20:48 DEBUG (MainThread) [custom_components.zha_new] Restore state for binary_sensor.lumi_lumi_sensor_motion_aq2_02e99837_1_occupancy:
2019-08-08 14:20:49 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1:0x0006] set config report status: [[<ConfigureReportingResponseRecord status=0 direction=0 attrid=0>]]
2019-08-08 14:20:49 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1:0x0006] set config report status: [[<ConfigureReportingResponseRecord status=0 direction=0 attrid=0>]]
2019-08-08 14:20:49 DEBUG (MainThread) [custom_components.zha_new] [0x2cd9:1:0x0008] set config report status: [[<ConfigureReportingResponseRecord status=0 direction=0 attrid=0>]]
2019-08-08 14:20:49 DEBUG (MainThread) [custom_components.zha_new] [0x378a:1:0x0008] set config report status: [[<ConfigureReportingResponseRecord status=0 direction=0 attrid=0>]]
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0x912a:2] endpoint init
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0x912a:2] node config for 00:0d:6f:00:0e:26:f3:4a-2: {}
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0x912a:2] pre call _custom_endpoint_init: {}
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0x912a:2] no call _custom_endpoint_init: 3326-L
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0x912a:2] node config for 00:0d:6f:00:0e:26:f3:4a-2: {}
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0x912a:2] config reports skipped for 00:0d:6f:00:0e:26:f3:4a, already joined 
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0x912a:2] 2:profile 49887, component: None cluster:[set(), set()]
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0x912a] Exit device init 00:0d:6f:00:0e:26:f3:4a
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new] [0xcf71] Exit device init 00:15:8d:00:02:e9:98:37
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new.sensor] [0x912a:1] initialize cluster listeners: ([1026, 1280]/[]) 
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new.sensor] Return make_sensor - 00:0d:6f:00:0e:26:f3:4a
2019-08-08 14:20:50 DEBUG (MainThread) [custom_components.zha_new.sensor] Create sensor.zha: sensor.centralite_3326_l_0e26f34a_1_temperature
2019-08-08 14:20:51 DEBUG (MainThread) [custom_components.zha_new.sensor] [0xcf71:1] initialize cluster listeners: ([1024, 1280]/[]) 
2019-08-08 14:20:51 DEBUG (MainThread) [custom_components.zha_new.sensor] Return make_sensor - 00:15:8d:00:02:e9:98:37
2019-08-08 14:20:51 DEBUG (MainThread) [custom_components.zha_new.sensor] Create sensor.zha: sensor.lumi_unknown_02e99837_1_illuminance
2019-08-08 14:20:51 DEBUG (MainThread) [custom_components.zha_new] Restore state for sensor.centralite_3326_l_0e26f34a_1_temperature:
2019-08-08 14:20:51 DEBUG (MainThread) [custom_components.zha_new] Restore failed for sensor.centralite_3326_l_0e26f34a_1_temperature: could not convert string to float: 'unknown'
2019-08-08 14:20:51 DEBUG (MainThread) [custom_components.zha_new] Restore state for sensor.lumi_lumi_sensor_motion_aq2_02e99837_1_illuminance:
2019-08-08 14:20:51 DEBUG (MainThread) [custom_components.zha_new] Restore failed for sensor.lumi_lumi_sensor_motion_aq2_02e99837_1_illuminance: 'IlluminanceSensor' object has no attribute '_groups'
2019-08-08 14:21:04 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1:0x0006]: : bind exceptional failed sendunicast reply timeout error
2019-08-08 14:21:05 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1:0x0006] set config report status: [[<ConfigureReportingResponseRecord status=0 direction=0 attrid=0>]]
2019-08-08 14:21:05 DEBUG (MainThread) [custom_components.zha_new] [0xa942:1:0x0008] set config report status: [[<ConfigureReportingResponseRecord status=0 direction=0 attrid=0>]]
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] light.guest_room_lamp async_update
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] light.living_room_lamp async_update
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] light.dining_room_lamp async_update
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] cluster:6 attribute=value received: 0=Bool.false
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light]  poll received for light.guest_room_lamp : {'on_off': <Bool.false: 0>}
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.guest_room_lamp is false
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] light.guest_room_lamp get membership failed: 'list' object has no attribute 'get_membership'
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] cluster:6 attribute=value received: 0=Bool.false
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light]  poll received for light.living_room_lamp : {'on_off': <Bool.false: 0>}
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.living_room_lamp is false
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] light.living_room_lamp get membership failed: 'list' object has no attribute 'get_membership'
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] cluster:6 attribute=value received: 0=Bool.false
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light]  poll received for light.dining_room_lamp : {'on_off': <Bool.false: 0>}
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.dining_room_lamp is false
2019-08-08 14:22:09 DEBUG (MainThread) [custom_components.zha_new.light] light.dining_room_lamp get membership failed: 'list' object has no attribute 'get_membership'
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] light.dining_room_lamp async_update
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] light.guest_room_lamp async_update
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] light.living_room_lamp async_update
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] cluster:6 attribute=value received: 0=Bool.false
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light]  poll received for light.guest_room_lamp : {'on_off': <Bool.false: 0>}
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.guest_room_lamp is false
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] light.guest_room_lamp get membership failed: 'list' object has no attribute 'get_membership'
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] cluster:6 attribute=value received: 0=Bool.false
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light]  poll received for light.living_room_lamp : {'on_off': <Bool.false: 0>}
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.living_room_lamp is false
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] light.living_room_lamp get membership failed: 'list' object has no attribute 'get_membership'
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] cluster:6 attribute=value received: 0=Bool.false
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light]  poll received for light.dining_room_lamp : {'on_off': <Bool.false: 0>}
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.dining_room_lamp is false
2019-08-08 14:22:40 DEBUG (MainThread) [custom_components.zha_new.light] light.dining_room_lamp get membership failed: 'list' object has no attribute 'get_membership'
andrewlphilpott commented 5 years ago

And here's the log with bellows debugging:

2019-08-08 14:25:00 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for zha_new which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-08-08 14:25:35 DEBUG (MainThread) [bellows.uart] Start sendq loop
2019-08-08 14:25:38 DEBUG (MainThread) [bellows.uart] Sending: RESET
2019-08-08 14:25:38 DEBUG (MainThread) [bellows.uart] Sending: b'1ac038bc7e'
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] RSTACK Version: 2 Reason: RESET_SOFTWARE frame: b'c1020b0a527e'
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Reset success
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.ezsp] Send command version
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Sending: b'004221a850ed2c7e'
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0142a1a8502805e67f627e'
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.ezsp] Application frame 0 (version) received
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'00800004021054'
2019-08-08 14:25:40 INFO (MainThread) [bellows.ezsp] EMBER Stack version 0x5410:
2019-08-08 14:25:40 INFO (MainThread) [bellows.zigbee.application] EZSP StackVersion : 0x5410
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Sending: b'7d314321fb582815c3277e'
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1243a1fb54fb737e'
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:40 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'01805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.zigbee.application] Run receive queue poller
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'224021fb592f15226f7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2340a1fb54c6107e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'02805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'334121fb792b15a2d77e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3441a1fb54d32a7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'03805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'444621fb7d5e291514417e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4546a1fb5435d07e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'04805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'554721fb4d2815713f7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5647a1fb54a9ec7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'05805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'664421fb516a15637c7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6744a1fb54948f7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'06805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'774521fb4e3a15c82b7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7045a1fb5481b57e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'07805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'004a21fb453a1560fc7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'014aa1fb54e28c7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'08805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'7d314b21fb4a3a1586777e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'124ba1fb547eb07e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'09805300'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'224821fb629e1537457e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2348a1fb6305677e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:41 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'0a805337'
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.uart] Sending: b'334921fb475215c3f07e'
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3449a1fb5456e97e'
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'0b805300'
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:42 DEBUG (MainThread) [bellows.uart] Sending: b'444e21fb4f2215376c7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'454ea1fb54b0137e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'0c805300'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(1): b'4d4ea1fb54b23e7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] DUP Data frame SEQ(4)/ReTx(1): b'4d4ea1fb54b23e7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'554f21fb573e15510a7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'564fa1fb542c2f7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'0d805300'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'664c21fb55d515bccd7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'674ca1fb54114c7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'0e805300'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command getConfigurationValue
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'774d21fa531b2e7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'704da1fa543a150ceb7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 82 (getConfigurationValue) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'0f8052001000'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'005221fb463e0b7d31517e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0152a1fb547ce87e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'10805300'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command addEndpoint
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'7d315321aa552e14b7599448278a55924cbc4e27aed2e27e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1253a1aa54dd5a7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 2 (addEndpoint) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'11800200'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.zigbee.application] addEndpoint result: [<EzspStatus.SUCCESS: 0>]
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command addEndpoint
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'225021aa5974d5f251944b24aa459259c5f67e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2350a1aa54e0397e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 2 (addEndpoint) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'12800200'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.zigbee.application] addEndpoint result: [<EzspStatus.SUCCESS: 0>]
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command addEndpoint
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'335121aaa6cab4d359944b248b55b349ab697e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3451a1aa54f5037e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 2 (addEndpoint) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'13800200'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.zigbee.application] addEndpoint result: [<EzspStatus.SUCCESS: 0>]
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command networkInit
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'445621bfaf207e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4556a5bf5433bf7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 23 (networkInit) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'14841700'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5556b1b1c408f07e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 25 (stackStatusHandler) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'14901990'
2019-08-08 14:25:43 INFO (MainThread) [bellows.zigbee.application] Unused callhander received: stackStatusHandler : [<EmberStatus.NETWORK_UP: 144>]
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command getNetworkParameters
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'56572180a9637e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6657a180542b5d5502d2dbae6fde1b5a944127abedcf677302c139377e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 40 (getNetworkParameters) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'158028000148e75b46918bc58b8913080f0000000100f8ff07'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command setPolicy
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'675421fd517827957e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7754a1fd5421d47e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 85 (setPolicy) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'16805500'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command setPolicy
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'705521fd524b0c627e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0055a1fd542d327e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 85 (setPolicy) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'17805500'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command setPolicy
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'015a21fd542bafa77e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'115aa1fd5457d77e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 85 (setPolicy) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'18805500'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command getNodeId
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'125b218f89807e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'225ba18f542a856f7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 39 (getNodeId) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'1980270000'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command getEui64
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'2358218e9aac7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3358a18edb374bb959fb4725ef497e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 38 (getEui64) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'1a80268f1d5e0b006f0d00'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] enable run
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'345921cb5473817e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4459a1cb542a15b2f7c57e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'1b806300000000'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'455e21cb55855a7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'555ea1cb542a15b294e67e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'1c806300000000'
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:43 DEBUG (MainThread) [bellows.uart] Sending: b'565f21cb5629057e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'665fa1cb542a15b2a22e7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'1d806300000000'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'675c21cb5704477e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'775ca1cb542a15b200cb7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'1e806300000000'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'705d21cb50619a7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'005da1cb542a15b2cfbe7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'1f806300000000'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'016221cb513e6b7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1162a1cb542a15b266bd7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'20806300000000'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'126321cb5292347e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2263a1cb542a15b250757e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'21806300000000'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'236021cb53bf767e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3360a1cb542a15b2f2907e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'22806300000000'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'346121cb5c5ba37e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4461a1cb2482e07e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'23806370'
2019-08-08 14:25:44 DEBUG (MainThread) [bellows.zigbee.application] restore groups: set()
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 0
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.zigbee.application] [0x2cd9:0:0x0021] sendUnicast  on PROFIL_ID:0 TSN:1, Timeout:15
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 1
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.zigbee.application] [0x378a:0:0x0021] sendUnicast  on PROFIL_ID:0 TSN:2, Timeout:15
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 2
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.zigbee.application] [0xa942:0:0x0021] sendUnicast  on PROFIL_ID:0 TSN:3, Timeout:15
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Sending: b'4566219c54f339b259b54a25aa1593499c4f26bdecd5fb80fdc6476c807f39a7e842c33184ffa8d6d5d383ae7e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5566a19c5441e2d87e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'248034006b'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Sending: b'5667219c54a022b259b54a25aa1593499c4c25bdef9d2188fdc6476c807f39a7e842c33184ffa8d6d5d37d3a167e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6667a19c5446d9027e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'258034006c'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Sending: b'6764219c5468bcb259b54a25aa1593499c4d24bdee783499fdc6476c807f39a7e842c33184ffa8d6d5d33d587e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7764a19c544778d57e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:45 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'268034006d'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0764b19754f339b259b54a25aa1592499c2526abed17c27e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'26903f00d92c000021000000400000006b010000'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1764b19754a022b259b54a25aa1592499c2225abed5cf77e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'26903f008a37000021000000400000006c020000'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2764b1ed542a1593d9944a25aa5592936ef2fe871231658afd1bdf7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'2690450000002180000000000000daf2bcd92cffff020100'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3764b1ed542a1593d9944a25aa5592ea62e2ad9c12316589fdcc507e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'2690450000002180000000000000a3feac8a37ffff020200'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4764b1975468bcb259b54a25aa1592499c2324abedf6a27e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'26903f0042a9000021000000400000006d030000'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5764b1ed542a1593d9944a25aa55925f63e5650212316588fdaba27e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'269045000000218000000000000016ffab42a9ffff020300'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 0
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.zigbee.application] [0x2cd9:1:0x0006] sendUnicast  on PROFIL_ID:260 TSN:4, Timeout:15
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 1
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.zigbee.application] [0x378a:1:0x0006] sendUnicast  on PROFIL_ID:260 TSN:5, Timeout:15
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'7665219c54f339b658924a24ab1593499c4a23a0edca618bfdc67388fc263dc91d7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 2
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.zigbee.application] [0xa942:1:0x0006] sendUnicast  on PROFIL_ID:260 TSN:6, Timeout:15
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6065a19c544430227e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'278034006e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'076a219c54a022b658924a24ab1593499c4b22a0edcb618bfdc67388fc263d8d547e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'716aa19c54451ade7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'288034006f'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'106b219c5468bcb658924a24ab1593499c4821a0edc8618bfdc67388fc263d7f6e7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'026ba19c545ad82d7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'2980340070'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'126bb19754f339b658924a24ab1593499c2023abedab7d7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'29903f00d92c040106000101400100006e040000'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'226bb1ed542e14b459954b65aa5592926cf2fe8712316383f9c16309627e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'2990450004010600010140000000dbf0bcd92cffff0408040700'
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 2
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.zigbee.application] [0x2cd9:0:0x0021] sendUnicast  on PROFIL_ID:0 TSN:7, Timeout:15
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:46 DEBUG (MainThread) [bellows.uart] Sending: b'2368219c54f339b259b54a25aa1593499c4920bdead5fb80fdc6476c807f37a7e842c33184ffa8d6d5d3889f7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3368a19c545b4cf27e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'2a80340071'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4368b19754a022b658924a24ab1593499c2122abed39e47e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'2a903f008a37040106000101400100006f050000'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5368b19754f339b259b54a25aa1593499c3f20abedf77a7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'2a903f00d92c0000210000004001000071070000'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6368b1ed542a1593d9944a25aa55929573f2fe871231658cfdd2df7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'2a90450000002180000000000000dcefbcd92cffff020700'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7368b1ed542e14b459954b65aa5592ed63e5ad9c12316383f8c163dea67e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'2a90450004010600010140000000a4ffab8a37ffff0408050700'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0368b1975468bcb658924a24ab1593499c3e21abedcae17e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'2a903f0042a90401060001014001000070060000'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1368b1ed542e14b459954b65aa55925e65e2650212316383fbc1638e217e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'2a9045000401060001014000000017f9ac42a9ffff0408060700'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 0
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] [0x378a:0:0x0021] sendUnicast  on PROFIL_ID:0 TSN:8, Timeout:15
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 1
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] [0xa942:0:0x0021] sendUnicast  on PROFIL_ID:0 TSN:9, Timeout:15
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 2
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] [0x2cd9:1:0x0008] sendUnicast  on PROFIL_ID:260 TSN:10, Timeout:15
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'3269219c54a022b259b54a25aa1593499c462fbde59d2188fdc6476c807f37a7e842c33184ffa8d6d5d30a647e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2469a19c545804057e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'2b80340072'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'436e219c5468bcb259b54a25aa1593499c472ebde4783499fdc6476c807f37a7e842c33184ffa8d6d5d37c5a7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'356ea19c54592cd47e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'2c80340073'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'546f219c54f339b6589c4a24ab1593499c442da7edc4618bfdc64388fc263da6672d7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'466fa19c545e7d1e7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'2d80340074'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'566fb19754a022b259b54a25aa1593499c3c2fabedb7467e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'2d903f008a370000210000004001000072080000'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'666fb1ed542a1593d9944a25aa5592ec6be2ad9c12316583fd52a47e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'2d90450000002180000000000000a5f7ac8a37ffff020800'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 2
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] [0x378a:1:0x0008] sendUnicast  on PROFIL_ID:260 TSN:11, Timeout:15
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'676c219c54a022b6589c4a24ab1593499c452ca7edc5618bfdc64388fc263da69ebc7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'776ca19c545fe9c17e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'2e80340075'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'076cb19754f339b6589c4a24ab1593499c3a2dabed677f7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'2e903f00d92c04010800010140010000740a0000'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'176cb1ed542e14ba59954b65aa55929774f2fe8712316383f7c163141b7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'2e90450004010800010140000000dee8bcd92cffff04080a0700'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'276cb19754a022b6589c4a24ab1593499c3b2cabede6c57e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'2e903f008a3704010800010140010000750b0000'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'376cb1975468bcb259b54a25aa1593499c3d2eabed15467e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'2e903f0042a90000210000004001000073090000'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'476cb1ed542a1593d9944a25aa55925161e2650212316582fdcf1f7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'2e9045000000218000000000000018fdac42a9ffff020900'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'576cb1ed542e14ba59954b65aa5592ef63e2ad9c12316383f6c16397787e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'2e90450004010800010140000000a6ffac8a37ffff04080b0700'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'676cb1ed542e14b459954b25aa5592ee60e5ad9c1231609311cc6389ec7e522b7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'2e90450004010600010100000000a7fcab8a37ffff0718ec0a00001000'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'776cb1ed542e14ba59954b25aa5592e164e2ad9c1231609310cc6389dcdb58fe7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'2e90450004010800010100000000a8f8ac8a37ffff0718ed0a000020a5'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] frame handler exception, handle_message() got an unexpected keyword argument 'message_type'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] > Traceback (most recent call last):

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 263, in _pull_frames
    self.ezsp_callback_handler(frame_name, args)

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 231, in ezsp_callback_handler
    self._handle_frame(*args)

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 301, in _handle_frame
    message_type=message_type)

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] > TypeError: handle_message() got an unexpected keyword argument 'message_type'

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] frame handler exception, handle_message() got an unexpected keyword argument 'message_type'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] > Traceback (most recent call last):

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 263, in _pull_frames
    self.ezsp_callback_handler(frame_name, args)

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 231, in ezsp_callback_handler
    self._handle_frame(*args)

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 301, in _handle_frame
    message_type=message_type)

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] > TypeError: handle_message() got an unexpected keyword argument 'message_type'

2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 0
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.zigbee.application] [0xa942:1:0x0008] sendUnicast  on PROFIL_ID:260 TSN:12, Timeout:15
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'706d219c5468bcb6589c4a24ab1593499c422ba7edc2618bfdc64388fc263da65cb17e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'006da19c545cfe2e7e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:25:47 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'2f80340076'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'106db1ed542e14b459954b25aa55925065e26502123160939fcc6389ec7ed56a7e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'2f9045000401060001010000000019f9ac42a9ffff0718620a00001000'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] frame handler exception, handle_message() got an unexpected keyword argument 'message_type'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] > Traceback (most recent call last):

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 263, in _pull_frames
    self.ezsp_callback_handler(frame_name, args)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 231, in ezsp_callback_handler
    self._handle_frame(*args)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 301, in _handle_frame
    message_type=message_type)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] > TypeError: handle_message() got an unexpected keyword argument 'message_type'

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'206db1975468bcb6589c4a24ab1593499c382babedbad07e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'2f903f0042a904010800010140010000760c0000'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'306db1ed542e14ba59954b65aa55925361e5650212316383f1c1639fc87e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'2f904500040108000101400000001afdab42a9ffff04080c0700'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'406db1ed542e14ba59954b25aa55929671f2fe87123160936ccc6389dcdbcc4a7e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'2f90450004010800010100000000dfedbcd92cffff0718910a000020a5'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] frame handler exception, handle_message() got an unexpected keyword argument 'message_type'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] > Traceback (most recent call last):

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 263, in _pull_frames
    self.ezsp_callback_handler(frame_name, args)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 231, in ezsp_callback_handler
    self._handle_frame(*args)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 301, in _handle_frame
    message_type=message_type)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] > TypeError: handle_message() got an unexpected keyword argument 'message_type'

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'506db1ed542e14ba59954b25aa55925262e56502123160939ecc6389dcdbb6657e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'2f904500040108000101000000001bfeab42a9ffff0718630a000020a5'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] frame handler exception, handle_message() got an unexpected keyword argument 'message_type'
2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] > Traceback (most recent call last):

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 263, in _pull_frames
    self.ezsp_callback_handler(frame_name, args)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 231, in ezsp_callback_handler
    self._handle_frame(*args)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] >   File "/config/deps/lib/python3.7/site-packages/bellows/zigbee/application.py", line 301, in _handle_frame
    message_type=message_type)

2019-08-08 14:25:48 DEBUG (MainThread) [bellows.zigbee.application] > TypeError: handle_message() got an unexpected keyword argument 'message_type'

2019-08-08 14:26:35 DEBUG (MainThread) [bellows.zigbee.application] watchdog: running
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Send command neighborCount
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 0
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.zigbee.application] [0x2cd9:1:0x0006] sendUnicast  on PROFIL_ID:260 TSN:13, Timeout:15
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 1
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.zigbee.application] [0x378a:1:0x0006] sendUnicast  on PROFIL_ID:260 TSN:14, Timeout:15
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.zigbee.application] pending message queue length: 2
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.zigbee.application] [0xa942:1:0x0006] sendUnicast  on PROFIL_ID:260 TSN:15, Timeout:15
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'067221d2cbd97e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6172a1d257de677e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 122 (neighborCount) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'30807a03'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'1773219c54f339b658924a24ab1593499c432aaeedc3678bfd6c607e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7273a19c545deb217e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'3180340077'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0273b19754f339b658924a24ab1593499c392aabed851b7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(0)/ReTx(0): b'31903f00d92c04010600010140010000770d0000'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1273b1ed542e14b459954b65aa5592a964f2fe8712316f83f0c76389fc6e3f84977e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(1)/ReTx(0): b'3190450004010600010140000000e0f8bcd92cffff08080d010000001000'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'2270219c54a022b658924a24ab1593499c4029aeedc0678bfd8bcf7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2370a19c5452c1287e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(2)/ReTx(0): b'3280340078'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'3371219c5468bcb658924a24ab1593499c4128aeedc1678bfdd73f7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3370b19754a022b658924a24ab1593499c3629abedcd757e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(3)/ReTx(0): b'32903f008a3704010600010140010000780e0000'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4471a19c5453ec017e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(4)/ReTx(0): b'3380340079'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5471b1ed542e14b459954b65aa5592e061e5ad9c12316f83f3c76389fc6e3fd86f7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(5)/ReTx(0): b'3390450004010600010140000000a9fdab8a37ffff08080e010000001000'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6471b1975468bcb658924a24ab1593499c3728abed5b137e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(6)/ReTx(0): b'33903f0042a904010600010140010000790f0000'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7471b1ed542e14b459954b65aa55925560e5650212316f83f2c76389fc6e3f25167e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-08-08 14:27:04 DEBUG (MainThread) [bellows.uart] Process Data frame SEQ(7)/ReTx(0): b'33904500040106000101400000001cfcab42a9ffff08080f010000001000'
andrewlphilpott commented 4 years ago

Closing this because I ended up nuking my entire HA setup and starting from scratch.