sendunicast reply timeout error

[andrewlphilpott]

At some point between this morning and now, my zha_new install stopped working without any changes. I'm on HA version 0.92.2 and I'm not really sure where to start to try to figure out what's happening. I haven't made any updates in the last week or so, so I have no idea what caused this issue (haven't even interacted with the HA UI since probably Sunday).

On startup, I'm getting several errors. Looking at my log, I'm seeing several instances of

WARNING (MainThread) [homeassistant.components.light] Setup of platform zha_new is taking over 10 seconds.

and

set config report exeptional failed: sendunicast reply timeout error

as well as

File "/config/deps/lib/python3.7/site-packages/zigpy/application.py", line 166, in run_topology
File "/config/deps/lib/python3.7/site-packages/zigpy/application.py", line 181, in update_topology
File "/config/deps/lib/python3.7/site-packages/zigpy/application.py", line 146, in get_device

Can anybody point me in the right direction?

[Yoda-x]

Hi, can you send over the full debug report. Thanks

[andrewlphilpott]

Sure. Here's the full log after a recent restart (I've got some issues I need to fix with other components that I've been putting off). For some reason on this restart I didn't get the zigpy errors.

2019-06-05 08:49:19 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for alexa_media 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-06-05 08:49:20 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-06-05 08:49:20 WARNING (MainThread) [homeassistant.components.http] Configuring trusted_networks via the http component has been deprecated. Use the trusted networks auth provider instead. For instructions, see https://www.home-assistant.io/docs/authentication/providers/#trusted-networks
2019-06-05 08:49:25 ERROR (MainThread) [homeassistant.setup] Error during setup of component alexa_media
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeassistant/setup.py", line 156, in _async_setup_component
    component.setup, hass, processed_config)  # type: ignore
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/alexa_media/__init__.py", line 103, in setup
    account.get(CONF_DEBUG))
  File "/config/deps/lib/python3.7/site-packages/alexapy/alexalogin.py", line 46, in __init__
    self.login_with_cookie()
  File "/config/deps/lib/python3.7/site-packages/alexapy/alexalogin.py", line 83, in login_with_cookie
    self.login(cookies=cookies)
  File "/config/deps/lib/python3.7/site-packages/alexapy/alexalogin.py", line 238, in login
    self._data = self.get_inputs(soup)
  File "/config/deps/lib/python3.7/site-packages/alexapy/alexalogin.py", line 110, in get_inputs
    for field in form.find_all('input'):
AttributeError: 'NoneType' object has no attribute 'find_all'
2019-06-05 08:49:33 ERROR (MainThread) [homeassistant.components.sensor] fedex: Error on device update!
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/fedexdeliverymanager/__init__.py", line 64, in wrapped
    return function(*args)
  File "/usr/local/lib/python3.7/site-packages/fedexdeliverymanager/__init__.py", line 103, in get_packages
    raise FedexError(err)
fedexdeliverymanager.FedexError: failed to get shipment list: Relogin

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homeassistant/helpers/entity_platform.py", line 261, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/local/lib/python3.7/site-packages/homeassistant/helpers/entity.py", line 377, in async_device_update
    await self.hass.async_add_executor_job(self.update)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/homeassistant/util/__init__.py", line 224, in wrapper
    result = method(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/homeassistant/components/fedex/sensor.py", line 85, in _update
    for package in fedexdeliverymanager.get_packages(self._session):
  File "/usr/local/lib/python3.7/site-packages/fedexdeliverymanager/__init__.py", line 66, in wrapped
    _login(*args)
  File "/usr/local/lib/python3.7/site-packages/fedexdeliverymanager/__init__.py", line 82, in _login
    raise FedexError('could not login')
fedexdeliverymanager.FedexError: could not login
2019-06-05 08:49:36 ERROR (SyncWorker_7) [homeassistant.components.ups.sensor] Could not connect to UPS My Choice account
2019-06-05 08:49:43 WARNING (MainThread) [homeassistant.components.light] Setup of platform zha_new is taking over 10 seconds.
2019-06-05 08:49:43 WARNING (MainThread) [homeassistant.components.light] Setup of platform zha_new is taking over 10 seconds.
2019-06-05 08:49:43 WARNING (MainThread) [homeassistant.components.light] Setup of platform zha_new is taking over 10 seconds.
2019-06-05 08:49:43 WARNING (MainThread) [homeassistant.components.light] Setup of platform zha_new is taking over 10 seconds.
2019-06-05 08:49:54 ERROR (MainThread) [custom_components.zha_new] [0x2a7e:1:0x0006] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:49:54 ERROR (MainThread) [custom_components.zha_new] [0xb138:1:0x0006] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:49:54 ERROR (MainThread) [custom_components.zha_new] [0x6849:1:0x0006] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:50:13 ERROR (MainThread) [custom_components.zha_new] [0x2a7e:1:0x0008] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:50:13 ERROR (MainThread) [custom_components.zha_new] [0xb138:1:0x0008] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:50:13 ERROR (MainThread) [custom_components.zha_new] [0x6849:1:0x0008] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:50:13 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0006] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:50:33 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0008] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:50:33 ERROR (MainThread) [homeassistant.components.light] Setup of platform zha_new is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2019-06-05 08:50:48 ERROR (SyncWorker_11) [homeassistant.components.waze_travel_time.sensor] Error on retrieving data: empty response
2019-06-05 08:50:55 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.dining_room_lamp is taking over 10 seconds
2019-06-05 08:50:55 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.living_room_lamp is taking over 10 seconds
2019-06-05 08:50:55 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.guest_room_lamp is taking over 10 seconds
2019-06-05 08:50:55 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.flood is taking over 10 seconds
2019-06-05 08:50:56 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:51:18 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300] set config report exeptional failed: sendunicast reply timeout error
2019-06-05 08:51:37 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300] set config report exeptional failed: sendunicast reply timeout error

Thanks!

Edit: It's also probably worth noting that I ended up restoring a snapshot from about a month ago when all my zigbee stuff was running smoothly, but the sendunicast error still persists.

[Yoda-x]

Not sure if this comes really from zha_new. The errors you see come from 3 bulbs. I assume they are off. Do you still have the logs from the time it stopped? And what devices you have configured under zha_new? Do you have a recent version of zha_new?

[andrewlphilpott]

Unfortunately, I don't have the logs from when it stopped. I'm not exactly sure when it even stopped, to be honest. It was working in the morning before I left for work and then I noticed in the evening that Alexa wasn't turning on any of my zigbee bulbs. When I checked my logs at that point, I was just seeing a bunch of sendunicast timeout errors.

I have 4 bulbs, 5 door/window sensors, and 3 motion sensors under zha_new. One of the bulbs used to be paired with a Lightify hub, but it kept disconnecting from that so I ended up adding it to zha_new. Maybe that bulb has something to do with it. It's been a bit of a problem bulb ever since I switched from Wink to HA. The weird thing is, that bulb was still working for a few minutes while none of my other zigbee devices worked.

Last night before restoring my old snapshot, I did try updating my zha_new version to the current one, but then I started getting an error saying that it couldn't load the https://github.com/Yoda-x/zigpy/archive/master.zip dependency.

[andrewlphilpott]

Just to rule it out, I went ahead and removed that Lightify bulb and restarted, but unfortunately I'm still getting the timeout.

[Yoda-x]

Hi, If a the bulbs are powered off they create this timeouts, that's normal if they were paired under an older zha_new version.

Please try do disable Alexa, to narrow down the problem.

The problem could arise from the failed load of the module. Most problems create hassio. What kind of installion you use?

[andrewlphilpott]

Ahhh okay. The bulbs are all powered off, so that probably has something to do with it.

I'll try disabling Alexa when I get home this evening, although that was working last night when this issue started. It not starting up is a new thing.

I guess worst case scenario, I could try wiping out all my zha_new devices and starting from scratch and see where that gets me.

I'm using a Raspberry Pi 3B+ with a HUSBZB-1.

[Yoda-x]

A raspi3b should be fine. I use them also. How you installed Hass? With the hassio image or with rasbian and a venv, or as a docker image?

[andrewlphilpott]

Yeah, I mean I've been using zha_new on the rpi for months without any issues. Hass is set up with the hassio image.

Last night I made sure all my bulbs were powered on and then tried restarting Hass, but I still got the same sendunicast error. Not sure what the deal is.

I think I'm just going to try removing all my zigbee devices and starting from scratch this evening. I realized yesterday that I have fewer devices than I originally thought, so it shouldn't be too much of a process. I had forgotten that a bunch of my sensors are actually zwave.

[Yoda-x]

Can you enable debugging for custom_components. zha_new and do a restart of Hass. Then please send over the full log. Or enable debug for everything. It's more noisy, but the best to get a full picture. After that you disable debug again. I think we should find the problem in the logs for the first 2 minutes. Just to confirm. You not updated Hass or any components the last view days?

[andrewlphilpott]

Yeah, I can do that. Here's the full debug log for zha_new. I haven't updated Hass or any components lately. Currently, I'm running off of a restored snapshot from May 13. A couple of bulbs have been reset to the original names that they were assigned when they were added initially, but other than that everything is as it was back in May.

Thanks for taking a look at this!

2019-06-06 14:16:55 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for alexa_media 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-06-06 14:16:55 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-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265] device init for <class 'str'>(lumi.sensor_magnet.aq2)(00:15:8d:00:03:12:22:08) -> Endpoints: [0, 1], already joined 
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:0] endpoint init
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:1] endpoint init
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:1] node config for 00:15:8d:00:03:12:22:08-1: {}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] Import DH lumi.sensor_magnet.aq2 success
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] custom_info for lumi.sensor_magnet.aq2: {'module': <module 'custom_components.device.lumi_sensor_magnet_aq2' from '/config/custom_components/device/lumi_sensor_magnet_aq2.py'>, '_custom_endpoint_init': <function _custom_endpoint_init at 0x6e4214b0>, '_custom_cluster_command': None, '_parse_attribute': <function _parse_attribute at 0x6e421540>, 'custom_parameters': None}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:1] pre call _custom_endpoint_init: {'module': <module 'custom_components.device.lumi_sensor_magnet_aq2' from '/config/custom_components/device/lumi_sensor_magnet_aq2.py'>, '_custom_endpoint_init': <function _custom_endpoint_init at 0x6e4214b0>, '_custom_cluster_command': None, '_parse_attribute': <function _parse_attribute at 0x6e421540>, 'custom_parameters': None}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:1] call _custom_endpoint_init: lumi.sensor_magnet.aq2
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:1] node config for 00:15:8d:00:03:12:22:08-1: {'in_cluster': [0, 6], 'type': 'binary_sensor'}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:1] config reports skipped for 00:15:8d:00:03:12:22:08, already joined 
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:1] 2:profile 260, component: binary_sensor cluster:[{0, 6}, {768, 1280, 4, 5, 6, 8}]
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265:1] Return from component general entity:00:15:8d:00:03:12:22:08
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x5265] Exit device init 00:15:8d:00:03:12:22:08
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df] device init for <class 'str'>(lumi.sensor_magnet.aq2)(00:15:8d:00:02:ec:f1:5e) -> Endpoints: [0, 1], already joined 
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:0] endpoint init
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:1] endpoint init
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:1] node config for 00:15:8d:00:02:ec:f1:5e-1: {}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:1] pre call _custom_endpoint_init: {'module': <module 'custom_components.device.lumi_sensor_magnet_aq2' from '/config/custom_components/device/lumi_sensor_magnet_aq2.py'>, '_custom_endpoint_init': <function _custom_endpoint_init at 0x6e4214b0>, '_custom_cluster_command': None, '_parse_attribute': <function _parse_attribute at 0x6e421540>, 'custom_parameters': None}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:1] call _custom_endpoint_init: lumi.sensor_magnet.aq2
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:1] node config for 00:15:8d:00:02:ec:f1:5e-1: {'in_cluster': [0, 6], 'type': 'binary_sensor'}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:1] config reports skipped for 00:15:8d:00:02:ec:f1:5e, already joined 
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:1] 2:profile 260, component: binary_sensor cluster:[{0, 6}, {768, 1280, 4, 5, 6, 8}]
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df:1] Return from component general entity:00:15:8d:00:02:ec:f1:5e
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x77df] Exit device init 00:15:8d:00:02:ec:f1:5e
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x16ba] device init for <class 'str'>(lumi.sensor_switch.aq2)(00:15:8d:00:02:05:95:ff) -> Endpoints: [0, 1], already joined 
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:0] endpoint init
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:1] endpoint init
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:1] node config for 00:15:8d:00:02:05:95:ff-1: {}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] Import DH lumi.sensor_switch.aq2 success
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] custom_info for lumi.sensor_switch.aq2: {'module': <module 'custom_components.device.lumi_sensor_switch_aq2' from '/config/custom_components/device/lumi_sensor_switch_aq2.py'>, '_custom_endpoint_init': <function _custom_endpoint_init at 0x6e3e2030>, '_custom_cluster_command': None, '_parse_attribute': <function _parse_attribute at 0x6e7cee40>, 'custom_parameters': None}
2019-06-06 14:17:09 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:1] pre call _custom_endpoint_init: {'module': <module 'custom_components.device.lumi_sensor_switch_aq2' from '/config/custom_components/device/lumi_sensor_switch_aq2.py'>, '_custom_endpoint_init': <function _custom_endpoint_init at 0x6e3e2030>, '_custom_cluster_command': None, '_parse_attribute': <function _parse_attribute at 0x6e7cee40>, 'custom_parameters': None}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:1] call _custom_endpoint_init: lumi.sensor_switch.aq2
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:1] node config for 00:15:8d:00:02:05:95:ff-1: {'in_cluster': [0, 6, 18], 'type': 'binary_sensor'}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:1] config reports skipped for 00:15:8d:00:02:05:95:ff, already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:1] 2:profile 260, component: binary_sensor cluster:[{0, 18, 6}, {768, 1280, 4, 5, 6, 8}]
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x16ba:1] Return from component general entity:00:15:8d:00:02:05:95:ff
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x16ba] Exit device init 00:15:8d:00:02:05:95:ff
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4] device init for <class 'str'>(lumi.sensor_switch.aq2)(00:15:8d:00:02:04:9c:d4) -> Endpoints: [0, 1], already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:0] endpoint init
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:1] endpoint init
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:1] node config for 00:15:8d:00:02:04:9c:d4-1: {}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:1] pre call _custom_endpoint_init: {'module': <module 'custom_components.device.lumi_sensor_switch_aq2' from '/config/custom_components/device/lumi_sensor_switch_aq2.py'>, '_custom_endpoint_init': <function _custom_endpoint_init at 0x6e3e2030>, '_custom_cluster_command': None, '_parse_attribute': <function _parse_attribute at 0x6e7cee40>, 'custom_parameters': None}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:1] call _custom_endpoint_init: lumi.sensor_switch.aq2
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:1] node config for 00:15:8d:00:02:04:9c:d4-1: {'in_cluster': [0, 6, 18], 'type': 'binary_sensor'}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:1] config reports skipped for 00:15:8d:00:02:04:9c:d4, already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:1] 2:profile 260, component: binary_sensor cluster:[{0, 18, 6}, {768, 1280, 4, 5, 6, 8}]
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4:1] Return from component general entity:00:15:8d:00:02:04:9c:d4
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xe5b4] Exit device init 00:15:8d:00:02:04:9c:d4
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449] device init for <class 'str'>(3326-L)(00:0d:6f:00:0e:26:f3:4a) -> Endpoints: [0, 1, 2], already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:0] endpoint init
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] endpoint init
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] node config for 00:0d:6f:00:0e:26:f3:4a-1: {}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] Import DH 3326-L failed: ("No module named 'custom_components.device.3326-l'",)
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] pre call _custom_endpoint_init: {}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] no call _custom_endpoint_init: 3326-L
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] node config for 00:0d:6f:00:0e:26:f3:4a-1: {}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] config reports skipped for 00:0d:6f:00:0e:26:f3:4a, already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] 2:profile 260, component: binary_sensor cluster:[{0, 1280, 1030, 7}, {768, 1280, 4, 5, 6, 8}]
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] Return from component general entity:00:0d:6f:00:0e:26:f3:4a
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x7449:1] Call single-cluster entity: 1026
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589] device init for <class 'str'>(lumi.sensor_motion.aq2)(00:15:8d:00:02:e9:98:37) -> Endpoints: [0, 1], already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:0] endpoint init
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] endpoint init
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] node config for 00:15:8d:00:02:e9:98:37-1: {}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] Import DH lumi.sensor_motion.aq2 success
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] custom_info for lumi.sensor_motion.aq2: {'module': <module 'custom_components.device.lumi_sensor_motion_aq2' from '/config/custom_components/device/lumi_sensor_motion_aq2.py'>, '_custom_endpoint_init': <function _custom_endpoint_init at 0x6e4214b0>, '_custom_cluster_command': None, '_parse_attribute': <function _parse_attribute at 0x6e421540>, 'custom_parameters': None}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] pre call _custom_endpoint_init: {'module': <module 'custom_components.device.lumi_sensor_motion_aq2' from '/config/custom_components/device/lumi_sensor_motion_aq2.py'>, '_custom_endpoint_init': <function _custom_endpoint_init at 0x6e4214b0>, '_custom_cluster_command': None, '_parse_attribute': <function _parse_attribute at 0x6e421540>, 'custom_parameters': None}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] call _custom_endpoint_init: lumi.sensor_motion.aq2
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] node config for 00:15:8d:00:02:e9:98:37-1: {'config_report': [[1030, 0, 10, 1800, 1], [1024, 0, 10, 1800, 10]], 'in_cluster': [0, 1030, 65535], 'out_cluster': []}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] config reports skipped for 00:15:8d:00:02:e9:98:37, already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] 2:profile 260, component: binary_sensor cluster:[{0, 1030, 65535}, set()]
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] Return from component general entity:00:15:8d:00:02:e9:98:37
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0xf589:1] Call single-cluster entity: 1024
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e] device init for <class 'str'>(SoftWhite)(7c:e5:24:00:00:03:46:53) -> Endpoints: [0, 1], already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:0] endpoint init
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1] endpoint init
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1] node config for 7c:e5:24:00:00:03:46:53-1: {}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] Import DH SoftWhite failed: ("No module named 'custom_components.device.softwhite'",)
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1] pre call _custom_endpoint_init: {}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1] no call _custom_endpoint_init: SoftWhite
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1] node config for 7c:e5:24:00:00:03:46:53-1: {}
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1] config reports skipped for 7c:e5:24:00:00:03:46:53, already joined 
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1] 2:profile 260, component: light cluster:[{768, 4096, 3, 4, 5, 6, 8}, set()]
2019-06-06 14:17:10 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1] Return from component general entity:7c:e5:24:00:00:03:46:53
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e] Exit device init 7c:e5:24:00:00:03:46:53
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138] device init for <class 'str'>(SoftWhite)(7c:e5:24:00:00:0b:9c:1b) -> Endpoints: [0, 1], already joined 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:0] endpoint init
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1] endpoint init
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1] node config for 7c:e5:24:00:00:0b:9c:1b-1: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1] pre call _custom_endpoint_init: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1] no call _custom_endpoint_init: SoftWhite
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1] node config for 7c:e5:24:00:00:0b:9c:1b-1: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1] config reports skipped for 7c:e5:24:00:00:0b:9c:1b, already joined 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1] 2:profile 260, component: light cluster:[{768, 4096, 3, 4, 5, 6, 8}, set()]
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1] Return from component general entity:7c:e5:24:00:00:0b:9c:1b
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xb138] Exit device init 7c:e5:24:00:00:0b:9c:1b
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849] device init for <class 'str'>(SoftWhite)(7c:e5:24:00:00:12:53:b6) -> Endpoints: [0, 1], already joined 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:0] endpoint init
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1] endpoint init
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1] node config for 7c:e5:24:00:00:12:53:b6-1: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1] pre call _custom_endpoint_init: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1] no call _custom_endpoint_init: SoftWhite
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1] node config for 7c:e5:24:00:00:12:53:b6-1: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1] config reports skipped for 7c:e5:24:00:00:12:53:b6, already joined 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1] 2:profile 260, component: light cluster:[{768, 4096, 3, 4, 5, 6, 8}, set()]
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1] Return from component general entity:7c:e5:24:00:00:12:53:b6
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0x6849] Exit device init 7c:e5:24:00:00:12:53:b6
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d] device init for <class 'str'>(LIGHTIFY BR RGBW)(84:18:26:00:00:06:43:6d) -> Endpoints: [0, 3], already joined 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:0] endpoint init
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] endpoint init
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] node config for 84:18:26:00:00:06:43:6d-3: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Import DH LIGHTIFY BR RGBW failed: ("No module named 'custom_components.device.lightify_br_rgbw'",)
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] pre call _custom_endpoint_init: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] no call _custom_endpoint_init: LIGHTIFY BR RGBW
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] node config for 84:18:26:00:00:06:43:6d-3: {}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] config reports skipped for 84:18:26:00:00:06:43:6d, already joined 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] 2:profile 260, component: light cluster:[{768, 4096, 3, 4, 5, 6, 8}, set()]
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] Return from component general entity:84:18:26:00:00:06:43:6d
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3] Call single-cluster entity: 2820
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x5265:1] initialize cluster listeners: -[(4, <zigpy.zcl.clusters.general.Groups object at 0x72af5d50>), (0, <zigpy.zcl.clusters.general.Basic object at 0x72b1dbb0>), (6, <zigpy.zcl.clusters.general.OnOff object at 0x72b1de30>)]- 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x5265:1] exit make binary-sensor 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] set Entity object: <class 'custom_components.zha_new.binary_sensor.OnOffSensor'>-00:15:8d:00:03:12:22:08_1_on_off 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] Return binary_sensor init-cluster {0: <zigpy.zcl.clusters.general.Basic object at 0x72b1dbb0>, 3: <zigpy.zcl.clusters.general.Identify object at 0x72b1df90>, 65535: <zigpy.zcl.clusters.manufacturer_specific.ManufacturerSpecificCluster object at 0x72b1dc10>, 6: <zigpy.zcl.clusters.general.OnOff object at 0x72b1de30>, 1280: <zigpy.zcl.clusters.security.IasZone object at 0x72b1dad0>}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x77df:1] initialize cluster listeners: -[(4, <zigpy.zcl.clusters.general.Groups object at 0x72af51f0>), (0, <zigpy.zcl.clusters.general.Basic object at 0x72b1de10>), (6, <zigpy.zcl.clusters.general.OnOff object at 0x72b1ddb0>)]- 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x77df:1] exit make binary-sensor 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] set Entity object: <class 'custom_components.zha_new.binary_sensor.OnOffSensor'>-00:15:8d:00:02:ec:f1:5e_1_on_off 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] Return binary_sensor init-cluster {0: <zigpy.zcl.clusters.general.Basic object at 0x72b1de10>, 3: <zigpy.zcl.clusters.general.Identify object at 0x72b1df50>, 65535: <zigpy.zcl.clusters.manufacturer_specific.ManufacturerSpecificCluster object at 0x72b1da90>, 6: <zigpy.zcl.clusters.general.OnOff object at 0x72b1ddb0>, 1280: <zigpy.zcl.clusters.security.IasZone object at 0x72b1d730>}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x16ba:1] initialize cluster listeners: -[(4, <zigpy.zcl.clusters.general.Groups object at 0x72af5c90>), (0, <zigpy.zcl.clusters.general.Basic object at 0x72b1dcd0>), (6, <zigpy.zcl.clusters.general.OnOff object at 0x72b1d150>)]- 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x16ba:1] exit make binary-sensor 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] set Entity object: <class 'custom_components.zha_new.binary_sensor.OnOffSensor'>-00:15:8d:00:02:05:95:ff_1_on_off 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] Return binary_sensor init-cluster {0: <zigpy.zcl.clusters.general.Basic object at 0x72b1dcd0>, 65535: <zigpy.zcl.clusters.manufacturer_specific.ManufacturerSpecificCluster object at 0x72b1df30>, 6: <zigpy.zcl.clusters.general.OnOff object at 0x72b1d150>, 1280: <zigpy.zcl.clusters.security.IasZone object at 0x72b1ddd0>}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0xe5b4:1] initialize cluster listeners: -[(4, <zigpy.zcl.clusters.general.Groups object at 0x72af5b90>), (0, <zigpy.zcl.clusters.general.Basic object at 0x72b1de90>), (6, <zigpy.zcl.clusters.general.OnOff object at 0x72b1d7d0>)]- 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0xe5b4:1] exit make binary-sensor 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] set Entity object: <class 'custom_components.zha_new.binary_sensor.OnOffSensor'>-00:15:8d:00:02:04:9c:d4_1_on_off 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] Return binary_sensor init-cluster {0: <zigpy.zcl.clusters.general.Basic object at 0x72b1de90>, 65535: <zigpy.zcl.clusters.manufacturer_specific.ManufacturerSpecificCluster object at 0x72b1d790>, 6: <zigpy.zcl.clusters.general.OnOff object at 0x72b1d7d0>, 1280: <zigpy.zcl.clusters.security.IasZone object at 0x72b1d810>}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x7449:1] initialize cluster listeners: -[(0, <zigpy.zcl.clusters.general.Basic object at 0x72b1d750>), (1280, <zigpy.zcl.clusters.security.IasZone object at 0x72af54d0>)]- 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0x7449:1] exit make binary-sensor 
2019-06-06 14:17:11 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-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] Return binary_sensor init-cluster {0: <zigpy.zcl.clusters.general.Basic object at 0x72b1d750>, 1: <zigpy.zcl.clusters.general.PowerConfiguration object at 0x72b1d770>, 3: <zigpy.zcl.clusters.general.Identify object at 0x72b1d650>, 32: <zigpy.zcl.clusters.general.PollControl object at 0x72b1d670>, 1026: <zigpy.zcl.clusters.measurement.TemperatureMeasurement object at 0x72b1d850>, 1280: <zigpy.zcl.clusters.security.IasZone object at 0x72af54d0>, 2821: <zigpy.zcl.clusters.homeautomation.Diagnostic object at 0x72af50d0>}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0xf589:1] initialize cluster listeners: -[(0, <zigpy.zcl.clusters.general.Basic object at 0x72af5990>), (1030, <zigpy.zcl.clusters.measurement.OccupancySensing object at 0x72af5450>), (65535, <zigpy.zcl.clusters.manufacturer_specific.ManufacturerSpecificCluster object at 0x72af5530>)]- 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] [0xf589:1] exit make binary-sensor 
2019-06-06 14:17:11 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-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] Return binary_sensor init-cluster {0: <zigpy.zcl.clusters.general.Basic object at 0x72af5990>, 65535: <zigpy.zcl.clusters.manufacturer_specific.ManufacturerSpecificCluster object at 0x72af5530>, 1030: <zigpy.zcl.clusters.measurement.OccupancySensing object at 0x72af5450>, 1024: <zigpy.zcl.clusters.measurement.IlluminanceMeasurement object at 0x72af58b0>, 1280: <zigpy.zcl.clusters.security.IasZone object at 0x72af5db0>, 1: <zigpy.zcl.clusters.general.PowerConfiguration object at 0x72af5370>, 3: <zigpy.zcl.clusters.general.Identify object at 0x72af54b0>}
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.light] [0x2a7e:1] initialize cluster listeners: ([4096, 3, 4, 5, 6, 8]/[]) 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.light] [0x2a7e:1] called to set reports
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.light] [0xb138:1] initialize cluster listeners: ([4096, 3, 4, 5, 6, 8]/[]) 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.light] [0xb138:1] called to set reports
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.light] [0x6849:1] initialize cluster listeners: ([4096, 3, 4, 5, 6, 8]/[]) 
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new.light] [0x6849:1] called to set reports
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for binary_sensor.balcony_door:
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for binary_sensor.basement_door:
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for binary_sensor.office_button:
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for binary_sensor.bedroom_button:
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for binary_sensor.bedroom_motion_sensor:
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for binary_sensor.office_motion_sensor:
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for light.ge_softwhite_00034653_1:
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for light.ge_softwhite_000b9c1b_1:
2019-06-06 14:17:11 DEBUG (MainThread) [custom_components.zha_new] Restore state for light.ge_softwhite_001253b6_1:
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0x7449:2] endpoint init
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0x7449:2] node config for 00:0d:6f:00:0e:26:f3:4a-2: {}
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0x7449:2] pre call _custom_endpoint_init: {}
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0x7449:2] no call _custom_endpoint_init: 3326-L
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0x7449:2] node config for 00:0d:6f:00:0e:26:f3:4a-2: {}
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0x7449:2] config reports skipped for 00:0d:6f:00:0e:26:f3:4a, already joined 
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0x7449:2] 2:profile 49887, component: None cluster:[set(), set()]
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0x7449] Exit device init 00:0d:6f:00:0e:26:f3:4a
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0xf589] Exit device init 00:15:8d:00:02:e9:98:37
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new] [0xd82d] Exit device init 84:18:26:00:00:06:43:6d
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] [0x7449:1] initialize cluster listeners: ([1026, 1280]/[]) 
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] Return make_sensor - 00:0d:6f:00:0e:26:f3:4a
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] Create sensor.zha: sensor.centralite_3326_l_0e26f34a_1_temperature
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] [0xf589:1] initialize cluster listeners: ([1024, 1280]/[]) 
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] Return make_sensor - 00:15:8d:00:02:e9:98:37
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] Create sensor.zha: sensor.lumi_lumi_sensor_motion_aq2_02e99837_1_illuminance
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] [0xd82d:3] initialize cluster listeners: ([2820, 1280]/[]) 
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] Return make_sensor - 84:18:26:00:00:06:43:6d
2019-06-06 14:17:13 DEBUG (MainThread) [custom_components.zha_new.sensor] Create sensor.zha: sensor.osram_lightify_br_rgbw_0006436d_3
2019-06-06 14:17:14 DEBUG (MainThread) [custom_components.zha_new] Restore state for sensor.bedroom_temperature_sensor:
2019-06-06 14:17:14 DEBUG (MainThread) [custom_components.zha_new] Restore failed for sensor.bedroom_temperature_sensor: could not convert string to float: 'unknown'
2019-06-06 14:17:14 DEBUG (MainThread) [custom_components.zha_new] Restore state for sensor.lumi_lumi_sensor_motion_aq2_02e99837_1_illuminance:
2019-06-06 14:17:14 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-06-06 14:17:14 DEBUG (MainThread) [custom_components.zha_new] Restore state for sensor.osram_lightify_br_rgbw_0006436d_3:
2019-06-06 14:17:14 DEBUG (MainThread) [custom_components.zha_new] Restore failed for sensor.osram_lightify_br_rgbw_0006436d_3: could not convert string to float: 'unknown'
2019-06-06 14:17:21 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1:0x0006]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:17:21 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1:0x0006]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:17:21 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1:0x0006]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:17:31 ERROR (MainThread) [custom_components.zha_new] [0x2a7e:1:0x0006] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:17:31 ERROR (MainThread) [custom_components.zha_new] [0xb138:1:0x0006] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:17:31 ERROR (MainThread) [custom_components.zha_new] [0x6849:1:0x0006] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:17:31 DEBUG (MainThread) [custom_components.zha_new.light] [0xd82d:3] initialize cluster listeners: ([768, 3, 4, 5, 6, 8]/[]) 
2019-06-06 14:17:31 DEBUG (MainThread) [custom_components.zha_new.light] [0xd82d:3] called to set reports
2019-06-06 14:17:31 DEBUG (MainThread) [custom_components.zha_new] Restore state for light.osram_lightify_br_rgbw_0006436d_3:
2019-06-06 14:17:41 DEBUG (MainThread) [custom_components.zha_new] [0x2a7e:1:0x0008]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:17:41 DEBUG (MainThread) [custom_components.zha_new] [0xb138:1:0x0008]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:17:41 DEBUG (MainThread) [custom_components.zha_new] [0x6849:1:0x0008]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:17:41 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3:0x0006]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:17:50 ERROR (MainThread) [custom_components.zha_new] [0x2a7e:1:0x0008] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:17:50 ERROR (MainThread) [custom_components.zha_new] [0xb138:1:0x0008] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:17:50 ERROR (MainThread) [custom_components.zha_new] [0x6849:1:0x0008] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:17:51 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0006] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:18:00 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3:0x0008]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:18:10 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0008] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:18:17 DEBUG (MainThread) [custom_components.zha_new.light] light.ge_softwhite_00034653_1 async_update
2019-06-06 14:18:17 DEBUG (MainThread) [custom_components.zha_new.light] light.osram_lightify_br_rgbw_0006436d_3 async_update
2019-06-06 14:18:17 DEBUG (MainThread) [custom_components.zha_new.light] light.ge_softwhite_000b9c1b_1 async_update
2019-06-06 14:18:17 DEBUG (MainThread) [custom_components.zha_new.light] light.ge_softwhite_001253b6_1 async_update
2019-06-06 14:18:20 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:18:30 DEBUG (MainThread) [custom_components.zha_new.light] poll for light.ge_softwhite_00034653_1 failed: sendunicast reply timeout error
2019-06-06 14:18:30 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.ge_softwhite_00034653_1 excepted: 'NoneType' object is not subscriptable
2019-06-06 14:18:30 DEBUG (MainThread) [custom_components.zha_new.light] poll for light.osram_lightify_br_rgbw_0006436d_3 failed: sendunicast reply timeout error
2019-06-06 14:18:30 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.osram_lightify_br_rgbw_0006436d_3 excepted: 'NoneType' object is not subscriptable
2019-06-06 14:18:30 DEBUG (MainThread) [custom_components.zha_new.light] poll for light.ge_softwhite_000b9c1b_1 failed: sendunicast reply timeout error
2019-06-06 14:18:30 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.ge_softwhite_000b9c1b_1 excepted: 'NoneType' object is not subscriptable
2019-06-06 14:18:31 DEBUG (MainThread) [custom_components.zha_new.light] poll for light.ge_softwhite_001253b6_1 failed: sendunicast reply timeout error
2019-06-06 14:18:31 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.ge_softwhite_001253b6_1 excepted: 'NoneType' object is not subscriptable
2019-06-06 14:18:31 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:18:40 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:18:48 DEBUG (MainThread) [custom_components.zha_new.light] light.ge_softwhite_000b9c1b_1 async_update
2019-06-06 14:18:48 DEBUG (MainThread) [custom_components.zha_new.light] light.ge_softwhite_001253b6_1 async_update
2019-06-06 14:18:48 DEBUG (MainThread) [custom_components.zha_new.light] light.ge_softwhite_00034653_1 async_update
2019-06-06 14:18:48 DEBUG (MainThread) [custom_components.zha_new.light] light.osram_lightify_br_rgbw_0006436d_3 async_update
2019-06-06 14:18:50 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300] set config report exeptional failed: sendunicast reply timeout error
2019-06-06 14:18:57 DEBUG (MainThread) [custom_components.zha_new.light] poll for light.ge_softwhite_000b9c1b_1 failed: sendunicast reply timeout error
2019-06-06 14:18:57 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.ge_softwhite_000b9c1b_1 excepted: 'NoneType' object is not subscriptable
2019-06-06 14:18:57 DEBUG (MainThread) [custom_components.zha_new.light] poll for light.ge_softwhite_001253b6_1 failed: sendunicast reply timeout error
2019-06-06 14:18:57 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.ge_softwhite_001253b6_1 excepted: 'NoneType' object is not subscriptable
2019-06-06 14:18:57 DEBUG (MainThread) [custom_components.zha_new.light] poll for light.ge_softwhite_00034653_1 failed: sendunicast reply timeout error
2019-06-06 14:18:57 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.ge_softwhite_00034653_1 excepted: 'NoneType' object is not subscriptable
2019-06-06 14:18:57 DEBUG (MainThread) [custom_components.zha_new.light] poll for light.osram_lightify_br_rgbw_0006436d_3 failed: sendunicast reply timeout error
2019-06-06 14:18:57 DEBUG (MainThread) [custom_components.zha_new.light] assumed state for light.osram_lightify_br_rgbw_0006436d_3 excepted: 'NoneType' object is not subscriptable
2019-06-06 14:19:00 DEBUG (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300]: : bind exceptional failed sendunicast reply timeout error
2019-06-06 14:19:08 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] alarm event [tsn:44] {'entity_id': 'binary_sensor.bedroom_motion_sensor', 'channel': 'IasZone', 'command': 'ALARM2', 'data': 1}
2019-06-06 14:19:08 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] alarm event [tsn:44] {'entity_id': 'binary_sensor.bedroom_motion_sensor', 'channel': 'IasZone', 'command': 'TAMPER', 'data': 1}
2019-06-06 14:19:08 DEBUG (MainThread) [custom_components.zha_new.binary_sensor] alarm event [tsn:44] {'entity_id': 'binary_sensor.bedroom_motion_sensor', 'channel': 'IasZone', 'command': 'RESTORE_REPORTS', 'data': 1}
2019-06-06 14:19:09 ERROR (MainThread) [custom_components.zha_new] [0xd82d:3:0x0300] set config report exeptional failed: sendunicast reply timeout error

[Yoda-x]

Nothing obvious to see. Maybe a hardware problem.

Please disable the custom_component debug and enable debug for bellows. Let's take a look on the hardware layer..

[andrewlphilpott]

Here's the debug log for bellows:

2019-06-06 15:18:17 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for alexa_media 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-06-06 15:18:17 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-06-06 15:18:22 DEBUG (MainThread) [bellows.uart] Start sendq loop
2019-06-06 15:18:23 DEBUG (MainThread) [bellows.uart] Sending: RESET
2019-06-06 15:18:23 DEBUG (MainThread) [bellows.uart] Sending: b'1ac038bc7e'
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] RSTACK Version: 2 Reason: RESET_SOFTWARE frame: b'c1020b0a527e'
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Reset success
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.ezsp] Send command version
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Sending: b'004221a850ed2c7e'
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0142a1a8502805e67f627e'
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.ezsp] Application frame 0 (version) received
2019-06-06 15:18:25 INFO (MainThread) [bellows.ezsp] EMBER Stack version 0x5410:
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Sending: b'7d314321fb582815c3277e'
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.zigbee.application] Run receive queue poller
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1243a1fb54fb737e'
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:18:25 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.uart] Sending: b'224021fb592f15226f7e'
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2340a1fb54c6107e'
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.uart] Sending: b'334121fb792b15a2d77e'
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3441a1fb54d32a7e'
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:18:28 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'444621fb7d5e291514417e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4546a1fb5435d07e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'554721fb4d2815713f7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5647a1fb54a9ec7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'664421fb510a1568567e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6744a1fb54948f7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'774521fb4e3a15c82b7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7045a1fb5481b57e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'004a21fb453a1560fc7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'014aa1fb54e28c7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'7d314b21fb4a2b15b6357e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'124ba1fb547eb07e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'224821fb629e1537457e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2348a1fb6305677e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'334921fb47161502f87e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3449a1fb5456e97e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'444e21fb4f2c1514637e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'454ea1fb54b0137e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:29 DEBUG (MainThread) [bellows.uart] Sending: b'554f21fb573e15510a7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'564fa1fb542c2f7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'664c21fb55d515bccd7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'674ca1fb54114c7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getConfigurationValue
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'774d21fa531b2e7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'704da1fa543a150ceb7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 82 (getConfigurationValue) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command setConfigurationValue
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'005221fb463e0b7d31517e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0152a1fb547ce87e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 83 (setConfigurationValue) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command addEndpoint
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'7d315321aa552e14b7599448278a55924cbc4e27aed2e27e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1253a1aa54dd5a7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 2 (addEndpoint) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.zigbee.application] addEndpoint result: [<EzspStatus.SUCCESS: 0>]
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command addEndpoint
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'225021aa5974d5f251944b24aa459259c5f67e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2350a1aa54e0397e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 2 (addEndpoint) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.zigbee.application] addEndpoint result: [<EzspStatus.SUCCESS: 0>]
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command networkInit
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'335121bf39e87e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3451a5bf54d5457e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 23 (networkInit) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4451b1b1c4f7d67e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 25 (stackStatusHandler) received
2019-06-06 15:18:30 INFO (MainThread) [bellows.zigbee.application] Unused callhander received: stackStatusHandler : [<EmberStatus.NETWORK_UP: 144>]
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getNetworkParameters
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'455621801e287e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5556a180542b5d5502d2dbae6fde1b5a944127abedcf677302c131ef7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 40 (getNetworkParameters) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command setPolicy
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'565721fd517a83297e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6657a1fd5414037e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 85 (setPolicy) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command setPolicy
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'675421fd524b74f67e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7754a1fd5421d47e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 85 (setPolicy) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command setPolicy
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'705521fd542bca627e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0055a1fd542d327e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 85 (setPolicy) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getNodeId
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'015a218f3ecb7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'115aa18f542ace527e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 39 (getNodeId) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getEui64
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'125b218e99a17e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'225ba18edb374bb959fb4725a3967e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 38 (getEui64) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] enable run
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'235821cb5466bb7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3358a1cb542a15b238b07e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'345921cb5563a07e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4459a1cb542a15b2f7c57e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'455e21cb56b5397e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'555ea1cb542a15b294e67e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'565f21cb5739247e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'665fa1cb542a15b2a22e7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'675c21cb5074a07e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'775ca1cb542a15b200cb7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'705d21cb5171bb7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'005da1cb542a15b2cfbe7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'016221cb520e087e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1162a1cb542a15b266bd7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:30 DEBUG (MainThread) [bellows.uart] Sending: b'126321cb5382157e'
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2263a1cb542a15b250757e'
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.ezsp] Send command getMulticastTableEntry
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.uart] Sending: b'236021cb5c4e997e'
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3360a1cb248e067e'
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:18:31 DEBUG (MainThread) [bellows.ezsp] Application frame 99 (getMulticastTableEntry) received
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:1
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:2
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:3
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0300 TSN:4
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Sending: b'3461219c54543fb259b54a25aa1593499c4f26bdec9d2188fdc6476c807f39a7e842c33184ffa8d6d5d39c3a7e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4461a19c54e61f257e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Sending: b'4566219c5412a4b259b54a25aa1593499c4c25bdefd5fb80fdc6476c807f39a7e842c33184ffa8d6d5d3b3a37e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5566a19c54e737f47e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Sending: b'5667219c54637d5db259b54a25aa1593499c4d24bdee783499fdc6476c807f39a7e842c33184ffa8d6d5d333527e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6667a19c54e44caa7e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Sending: b'6764219c5407cdb658944926a91593499c4a23aeedca6781bd64ab7e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7764a19c54e5ed7d7e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:18:33 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0764b19754543fb259b54a25aa1592499c8226cdedfd847e'
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1764b1975412a4b259b54a25aa1592499c8325cdedcec67e'
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2764b19754637db259b54a25aa1592499c8024cded19667e'
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3764b1975407cdb658944926a91592499c8123cded988f7e'
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:18:38 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x2a7e:0:0x0021
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:5
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Sending: b'7465219c54543fb658924a24ab1593499c4b22a0edcb618bfdc67388fc263da8f37e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:0:0x0021
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:6
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4065a19c54fa433f7e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Sending: b'056a219c5412a4b658924a24ab1593499c4821a0edc8618bfdc67388fc263dcae97e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:0:0x0021
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:7
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'516aa19c54fb69c37e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Sending: b'166b219c54637d5db658924a24ab1593499c4920a0edc9618bfdc67388fc263d19177e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0300
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0300 TSN:8
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'626ba19c54f8129d7e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Sending: b'2768219c5407cdb658944926a91593499c462faeedc6678cfd4df87e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7368a19c54f9b34a7e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:18:43 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0368b19754543fb658924a24ab1592499c9e22cded23547e'
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1368b1975412a4b658924a24ab1592499c9f21cded10167e'
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2368b19754637db658924a24ab1592499c9c20cdedc7b67e'
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3368b1975407cdb658944926a91592499c9d2fcdedb5b57e'
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:18:47 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x2a7e:1:0x0006
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:9
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Sending: b'3469219c54543fb259b54a25aa1593499c472ebde49d2188fdc6476c807f37a7e842c33184ffa8d6d5d3e0717e'
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:1:0x0006
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:10
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4469a19c54fe8e317e'
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Sending: b'456e219c5412a4b259b54a25aa1593499c442dbde7d5fb80fdc6476c807f37a7e842c33184ffa8d6d5d3cfe87e'
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:1:0x0006
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:11
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'556ea19c54ffa6e07e'
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] Sending: b'566f219c54637d5db259b54a25aa1593499c452cbde6783499fdc6476c807f37a7e842c33184ffa8d6d5d34f197e'
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0300
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:12
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:18:52 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'666fa19c54fcddbe7e'
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.uart] Sending: b'676c219c5407cdb259b54a25aa1593499c422bbde1a3248dfdc64591787d5d39a7e842c33184ffa8d6d5d121437e'
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'776ca19c54fd7c697e'
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:18:53 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'076cb19754543fb259b54a25aa1592499c9a2ecded77f87e'
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'176cb1975412a4b259b54a25aa1592499c9b2dcded44ba7e'
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'276cb19754637db259b54a25aa1592499c982ccded931a7e'
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'376cb1975407cdb259b54a25aa1592499c992bcded23917e'
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:18:57 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x2a7e:0:0x0021
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:1 PROFIL_ID:260 CLUSTER:0x0008 TSN:13
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Sending: b'746d219c54543fb6589c4a24ab1593499c432aa7edc3618bfdc64388fc263da6fe067e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:0:0x0021
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0008 TSN:14
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'406da19c54f2c01a7e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Sending: b'0572219c5412a4b6589c4a24ab1593499c4029a7edc0618bfdc64388fc263da6cb7a7e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:0:0x0021
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0008 TSN:15
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5172a19c54f3eebc7e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Sending: b'1673219c54637d5db6589c4a24ab1593499c4128a7edc1618bfdc64388fc263da6ce647e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:0:0x0021
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0006 TSN:16
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6273a19c54f095e27e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Sending: b'2770219c5407cdb658924a26a91593499c5e37a0edde618bfdc67388fc263df4b07e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7370a19c54f134357e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:19:02 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0370b19754543fb6589c4a24ab1592499c962acdedc94a7e'
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1370b1975412a4b6589c4a24ab1592499c9729cdedfa087e'
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2370b19754637db6589c4a24ab1592499c9428cded2da87e'
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3370b1975407cdb658924a26a91592499c9537cded7f9a7e'
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:19:07 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x2a7e:1:0x0008
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:1:0x0008
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:1:0x0008
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0006
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:17
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.uart] Sending: b'3471219c5407cdb259b54a25aa1593499c5f36bdfca3248dfdc64591787d5d37a7e842c33184ffa8d6d5d1f8197e'
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4471a19c54f6094e7e'
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:19:12 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:17 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:17 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5471b1975407cdb259b54a25aa1592499c9236cded71df7e'
2019-06-06 15:19:17 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:19:17 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:0:0x0021
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0008 TSN:18
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.uart] Sending: b'4676219c5407cdb6589c4a26a91593499c5c35a7eddc618bfdc64388fc263da695b47e'
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6576a19c54f70e137e'
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:19:22 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:23 DEBUG (MainThread) [bellows.zigbee.application] watchdog: running
2019-06-06 15:19:27 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:27 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7576b1975407cdb6589c4a26a91592499c9335cded5c5f7e'
2019-06-06 15:19:27 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:19:27 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0008
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:19
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.uart] Sending: b'5077219c5407cdb259b54a25aa1593499c5d34bdfea3248dfdc64591787d5d3fa4e842c33184ffa8d6d5d1f7727e'
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0677a19c54f405d97e'
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:19:32 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:36 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:36 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1677b1975407cdb259b54a25aa1592499c9034cdedefc67e'
2019-06-06 15:19:36 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:19:36 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Send command neighborCount
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:20
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:21
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0006 TSN:22
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:23
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'627421d2ea5a7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2774a1d25415707e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Application frame 122 (neighborCount) received
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'7375219c5412a4b658924a24ab1593499c5a33aeedda678bfd80f07e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3075a19c54f5f3167e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'047a219c54637d5db658924a24ab1593499c5b32aeeddb678bfdb75d7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'417aa19c54ca516f7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'157b219c5407cdb658924a26a91593499c5831aeedd8678bfd56287e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'527ba19c54cb3f7b7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'2678219c54543fb658924a24ab1593499c5930aeedd9678bfd3f7d317e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6378a19c54c88be67e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:19:38 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:41 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:41 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7378b1ed542e14b25c954b65ab55928a63f56edf12316e82a1c64789fc813fa744aa7e'
2019-06-06 15:19:41 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:19:41 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-06-06 15:19:42 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:42 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(1): b'7b78b1ed542e14b25c954b65ab55928a63f56edf12316e82a1c64789fc813fa7aed87e'
2019-06-06 15:19:42 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:19:42 DEBUG (MainThread) [bellows.uart] DUP Data frame SEQ(7)/ReTx(1): b'7b78b1ed542e14b25c954b65ab55928a63f56edf12316e82a1c64789fc813fa7aed87e'
2019-06-06 15:19:42 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:42 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0378b1ed542e14b25c954b65ab55928d63f56edf12316e82a0c64589fc813fa7848e7e'
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1378b1975412a4b658924a24ab1592499c9133cdedf41c7e'
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2378b19754637db658924a24ab1592499cae32cded40677e'
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:0:0x0021
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0300 TSN:24
2019-06-06 15:19:43 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3378b1975407cdb658924a26a91592499caf31cded34c17e'
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4378b19754543fb658924a24ab1592499cac30cdedbff37e'
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.zigbee.application] Invalid state on future - probably duplicate response: invalid state
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.zigbee.application] Invalid state on future - probably duplicate response: invalid state
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Sending: b'3579219c5407cdb658944926a91593499c563fa6edd6618bfec64288fc263da6eb90967e'
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.zigbee.application] sendunicast messagesend_ACK timeout
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.zigbee.application] sendunicast messagesend_ACK timeout
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5479a19c54c9d65b7e'
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:19:44 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:48 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:1:0x0006
2019-06-06 15:19:48 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:1:0x0006
2019-06-06 15:19:49 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:49 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6479b1975407cdb658944926a91592499cad3fcded18e47e'
2019-06-06 15:19:49 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:19:49 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0300
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:25
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.uart] Sending: b'477d5e219c5407cdb259b54a25aa1593499c573ebdf4a3248dfdc64591787d5d3fa4e842c33184ffa8d6d5d1c1567e'
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'757ea19c54ceb1c07e'
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:19:54 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:19:58 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:19:58 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'057eb1975407cdb259b54a25aa1592499caa3ecded04b97e'
2019-06-06 15:19:58 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:19:58 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:0:0x0021
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0300 TSN:26
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.uart] Sending: b'517f219c5407cdb658944926a91593499c543da6edd4618bf9c64288fc263da6eb20717e'
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'167fa19c54cf9a487e'
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:20:03 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:08 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:08 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'267fb1975407cdb658944926a91592499cab3dcded4c0c7e'
2019-06-06 15:20:08 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:20:08 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:27
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0006 TSN:28
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:29
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:30
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Sending: b'637c219c5412a4b658924a24ab1593499c553caeedd5678bfd83cb7e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'377ca19c54cc34517e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Sending: b'747d5d219c5407cdb658924a26a91593499c523baeedd2678bfdf3977e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'407da19c54cd03fc7e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Sending: b'0502219c54543fb658924a24ab1593499c533aaeedd3678bfddb7b7e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5102a19c54c2d5487e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Sending: b'1603219c54637d5db658924a24ab1593499c5039aeedd0678bfdeacc7e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6203a19c54c38e547e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:20:09 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0300
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:0 PROFIL_ID:0 CLUSTER:0x0021 TSN:31
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Sending: b'2700219c5407cdb259b54a25aa1593499c5138bdf2a3248dfdc64591787d5d3fa4e842c33184ffa8d6d5d1d0487e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7300a19c54c00fc17e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0300b1975412a4b658924a24ab1592499ca83ccded345f7e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1300b1975407cdb658924a26a91592499ca93bcded64037e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2300b19754543fb658924a24ab1592499ca63acdedbb757e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3300b19754637db658924a24ab1592499ca739cded700d7e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:20:13 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:18 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:18 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4300b1975407cdb259b54a25aa1592499ca438cdedd3c87e'
2019-06-06 15:20:18 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:20:18 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:18 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:1:0x0006
2019-06-06 15:20:18 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0006
2019-06-06 15:20:18 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x2a7e:1:0x0006
2019-06-06 15:20:18 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:1:0x0006
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.zigbee.application] watchdog: running
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:0:0x0021
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0300 TSN:32
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.uart] Sending: b'3501219c5407cdb658944926a91593499c6e07a6edee618bfac64288fc263da6eb5a0a7e'
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5401a19c54c148f87e'
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:20:23 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:28 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:28 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6401b1975407cdb658944926a91592499ca507cded4c027e'
2019-06-06 15:20:28 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:20:28 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:29 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:29 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7401b1ed542e14b25c954b65ab55928c63f26edf12316e82a3c64789fc813fa7ca287e'
2019-06-06 15:20:29 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:20:29 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-06-06 15:20:33 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0300
2019-06-06 15:20:39 DEBUG (MainThread) [bellows.ezsp] Send command neighborCount
2019-06-06 15:20:39 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:39 DEBUG (MainThread) [bellows.uart] Sending: b'400621d286147e'
2019-06-06 15:20:39 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:39 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0506a1d254f65a7e'
2019-06-06 15:20:39 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:20:39 DEBUG (MainThread) [bellows.ezsp] Application frame 122 (neighborCount) received
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:33
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:34
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0006 TSN:35
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:36
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Sending: b'5107219c54637d5db658924a24ab1593499c6f06aeedef678bfd25807e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1607a19c54c614ca7e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Sending: b'6204219c5412a4b658924a24ab1593499c6c05aeedec678bfd0dd47e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2704a19c54c780157e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Sending: b'7305219c5407cdb658924a26a91593499c6d04aeeded678bfdf6667e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3005a19c54c4c8e27e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Sending: b'040a219c54543fb658924a24ab1593499c6a03aeedea678bfd84fc7e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'410aa19c54c5bd067e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:20:40 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'510ab19754637db658924a24ab1592499ca206cded5e037e'
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'610ab1975412a4b658924a24ab1592499ca305cded0aab7e'
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'710ab1975407cdb658924a26a91592499ca004cded053f7e'
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'010ab19754543fb658924a24ab1592499ca103cdedd1c57e'
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:20:44 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:20:49 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:1:0x0006
2019-06-06 15:20:49 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:1:0x0006
2019-06-06 15:20:49 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0006
2019-06-06 15:20:49 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x2a7e:1:0x0006
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:37
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0006 TSN:38
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:39
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:40
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Sending: b'7d310b219c5412a4b658924a24ab1593499c6b02aeedeb678bfd22157e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'120ba19c54da4afd7e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Sending: b'2208219c5407cdb658924a26a91593499c6801aeede8678bfd096c7e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2308a19c54dbde227e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Sending: b'3309219c54543fb658924a24ab1593499c6900aeede9678bfdb2b37e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3409a19c54d896d57e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Sending: b'440e219c54637d5db658924a24ab1593499c660faeede6678bfd63897e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'450ea19c54d9e11c7e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:21:11 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:12 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:12 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'550eb1ed542e14b25c954b65ab55928f63f26edf12316e82a2c64589fc813fa75c007e'
2019-06-06 15:21:12 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:21:12 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'650eb1975412a4b658924a24ab1592499cbe02cded1c6d7e'
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'750eb1975407cdb658924a26a91592499cbf01cded90f17e'
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'050eb19754543fb658924a24ab1592499cbc00cded1bc37e'
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'150eb19754637db658924a24ab1592499cbd0fcdeda5da7e'
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:21:15 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:20 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:1:0x0006
2019-06-06 15:21:20 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0006
2019-06-06 15:21:20 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x2a7e:1:0x0006
2019-06-06 15:21:20 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:1:0x0006
2019-06-06 15:21:23 DEBUG (MainThread) [bellows.zigbee.application] watchdog: running
2019-06-06 15:21:40 DEBUG (MainThread) [bellows.ezsp] Send command neighborCount
2019-06-06 15:21:40 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:40 DEBUG (MainThread) [bellows.uart] Sending: b'520f21d2ee4a7e'
2019-06-06 15:21:40 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:40 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'260fa1d254e34b7e'
2019-06-06 15:21:40 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:21:40 DEBUG (MainThread) [bellows.ezsp] Application frame 122 (neighborCount) received
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xd82d DST_EP:3 PROFIL_ID:260 CLUSTER:0x0006 TSN:41
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x2a7e DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:42
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0xb138 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:43
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x6849 DST_EP:1 PROFIL_ID:260 CLUSTER:0x0006 TSN:44
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Sending: b'630c219c5407cdb658924a26a91593499c670eaeede7678bfd78017e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'370ca19c54de1ba47e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Sending: b'740d219c54543fb658924a24ab1593499c640daeede4678bfd4c6a7e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'400da19c54df2c097e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Sending: b'0512219c5412a4b658924a24ab1593499c650caeede5678bfdee8a7e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5112a19c54dc22ed7e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Sending: b'167d33219c54637d5db658924a24ab1593499c620baeede2678bfd9b0a7e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6213a19c54dd79f17e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:21:42 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7213b1975407cdb658924a26a91592499cba0ecded3c907e'
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0213b19754543fb658924a24ab1592499cbb0dcded34aa7e'
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1213b1975412a4b658924a24ab1592499cb80ccded84e07e'
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Data frame SEQ(2)/ReTx(0): b'2213b19754637db658924a24ab1592499cb90bcded0c887e'
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.uart] Sending: b'83401b7e'
2019-06-06 15:21:46 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:51 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xd82d:3:0x0006
2019-06-06 15:21:51 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x2a7e:1:0x0006
2019-06-06 15:21:51 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0xb138:1:0x0006
2019-06-06 15:21:51 DEBUG (MainThread) [bellows.zigbee.application] sendunicast reply timeout failure 0x6849:1:0x0006
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.uart] Data frame SEQ(3)/ReTx(0): b'3213b1ed502a15b459944a2dab55928e63f56edf12316ebb00396788fd673fa7eff17e'
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.uart] Sending: b'8430fc7e'
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.zigbee.application] sendUnicast to NWKID:0x7449 DST_EP:0 PROFIL_ID:0 CLUSTER:0x8006 TSN:45
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.ezsp] Send command sendUnicast
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.uart] add command to send queue: False-True
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.uart] Sending: b'2410219c546361b25992ca25aa1593499c630aadc0ce678bfcc764db7e'
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.uart] Data frame SEQ(4)/ReTx(0): b'4310a19c54d216647e'
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.uart] Sending: b'8520dd7e'
2019-06-06 15:21:54 DEBUG (MainThread) [bellows.ezsp] Application frame 52 (sendUnicast) received
2019-06-06 15:21:55 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:55 DEBUG (MainThread) [bellows.uart] Data frame SEQ(5)/ReTx(0): b'5310b197546361b25992ca25aa1593499cb60aabeda2ef7e'
2019-06-06 15:21:55 DEBUG (MainThread) [bellows.uart] Sending: b'8610be7e'
2019-06-06 15:21:55 DEBUG (MainThread) [bellows.ezsp] Application frame 63 (messageSentHandler) received
2019-06-06 15:21:56 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:56 DEBUG (MainThread) [bellows.uart] Data frame SEQ(6)/ReTx(0): b'6310b1ed542e14ab59954b65ab55928163f26edf12316b8a9dc763563e613fb7b8cdc2f42d7e'
2019-06-06 15:21:56 DEBUG (MainThread) [bellows.uart] Sending: b'87009f7e'
2019-06-06 15:21:56 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-06-06 15:21:59 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:21:59 DEBUG (MainThread) [bellows.uart] Data frame SEQ(7)/ReTx(0): b'7310b1ed542e14ab59954b65ab55928063f56edf12316b8a9cc763563e613fb7b8cdc2fa947e'
2019-06-06 15:21:59 DEBUG (MainThread) [bellows.uart] Sending: b'8070787e'
2019-06-06 15:21:59 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-06-06 15:22:02 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:22:02 DEBUG (MainThread) [bellows.uart] Data frame SEQ(0)/ReTx(0): b'0310b1ed542e14ab59954b65ab55928363f46edf12316b8a9fc763563e613fb7b8cdc256687e'
2019-06-06 15:22:02 DEBUG (MainThread) [bellows.uart] Sending: b'8160597e'
2019-06-06 15:22:02 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received
2019-06-06 15:22:05 DEBUG (MainThread) [bellows.uart] Status _send_task.done: False
2019-06-06 15:22:05 DEBUG (MainThread) [bellows.uart] Data frame SEQ(1)/ReTx(0): b'1310b1ed542e14ab59954b65ab55928263f46edf12316b8a9ec763563e613fb7b8cdc2a8047e'
2019-06-06 15:22:05 DEBUG (MainThread) [bellows.uart] Sending: b'82503a7e'
2019-06-06 15:22:05 DEBUG (MainThread) [bellows.ezsp] Application frame 69 (incomingMessageHandler) received

[Yoda-x]

looks good, usb stick works ok. I can see it send outs request over the air, but receives no answers Can you repair a bulb and see if it comes back?

[andrewlphilpott]

Sorry for the delayed response, busy day. I ended up removing the Lightify bulb that I thought was the source of the problem and I paired it back with my Lightify hub. I also re-paired the three remaining bulbs, but unfortunately that didn't help anything. I did notice the other day that some of the devices in zha_new seem to be working at least some of the time. The motion sensors have been detecting motion off and on, so it seems like maybe it's just the bulbs that are the issue. They're all the same type of bulb, but I'm not sure if that's related or not. I'm going to try resetting all of the bulbs.

Edit: Reset the bulbs, but still no luck.

[Yoda-x]

Hi Please make sure that all devicea like bulbs are powered off during pairing. Most of the bulbs act as routers. So, if you pair a device to zha_ new it may choose a bulb as parent. If you turn off the bulb via the wall plug the sensor looses its connection. So if you pair something, make sure it can only pair to something that stays up all the time.

In general zigbee tries to reestablish a mesh, but some devices may not have this capability.

[andrewlphilpott]

This actually reminds me of something I was meaning to ask. How do I completely remove a device? Removing it from the Entity Registry doesn't actually do anything as they show up again on restart. I'm guessing that's because they're still in the zigbee database. Do I need to go in and delete them from there?

[Yoda-x]

to remove a device please use the zha_new.remove service call. removing it from the entity registry only removes the HASS entity, but does not remove it from the zigbee db or tell the device to leave the network. without this functions the re-paring will not work completely and the init phase is skipped.

how did you removed the device from the entity registry? I will check if there is an option to call the low level zigbee functions via hass. Currently I do it other way round, the the zha_new.remove calls the hass functions to remove the device from hass and do the cleanup

[andrewlphilpott]

Oh wow, I'm dumb. I didn't realize the remove service call existed.

I just was going into Configuration > Entity Registry, clicking whatever device I wanted to remove, and hitting delete. HASS warns that you have to also remove the zha_new integration for it to take affect, which I did do, but obviously the devices weren't getting removed from the db so when I put zha_new back in, they were still there.

Edit: Well what do you know? Removing them properly seems to have fixed the issue. No more sendunicast timeout! Thanks for all of your help!

[Yoda-x]

I may add this to the wiki. I know the documentation is non existent.

A repairing of the bulbs also detected your bulbs new. They have now shorter timeouts, which don't cause the timeout message anymore. Let me know if we can close the ticket and everything is ok for you.

[andrewlphilpott]

I think we're good. I'll go ahead and close this. Thanks again for the help!