Zigbee binding

[ptmuldoon (Paul Muldoon)]

Well. I know the zigbee has been very unreliable for me via Openhab, and perhaps that is the fault of stick? I am using the Dual Zwave/Zigbee stick, the HUSBZB-1 and I don’t know how to determine what kind of firmware is on it.

I have limited USB ports, so really need a dual stick if possible. So if the HUSBZB-1 uses the CC2531 firmwware mentioned, and if someone can provide some basic instructions, I can try and compile and update my stick to test.

[chris (Chris Jackson)]

@ptmuldoon

I don’t know how to determine what kind of firmware is on it.

Just look in PaperUI - it should be shown there.

@ptmuldoon

if the HUSBZB-1 uses the CC2531

It doesn’t - it uses the Silabs Ember chipset.

[ptmuldoon (Paul Muldoon)]

Ok, so its back to the beginning in trying to understand why I my zigbee stops working. I tested yesterday on a different VM setup, and was able to pair a few bulbs fine. But then the lights stopped updating a short while later although the OH2 logs looked pretty normal with the items showing as updated although they never actually did.

If you have any ideas, I hope to try and spend some more time looking at things tonight.

[puzzle-star (Pedro Garcia)]

@chris

> Is there a specific thread to discuss on CC2531 firmware changes?

I don’t think so (of course you could start one )…

Done

[curlyel]

Hi @Chris,
I’m experience another strange serial port issue with the Zigbee-binding:

210 │ Active   │  80 │ 2.3.0                  │ ZigBee Binding
211 │ Active   │  80 │ 2.3.0                  │ ZigBee CC2531 Binding

When the coordinator is the only USB-serial device plugged into the system, the binding is initializing it.
But when I have a couple of other serial devices connected, it fails permanently.

Well, I’m aware of some of the common issues regarding USB-to-serial devices connected to Linux. So I have symlinked the Zigbee coordinator ( /dev/zigbee, since this had the same issue now to /dev/ttyUSB99 to match a common pattern):

SUBSYSTEM=="tty",ATTRS{idVendor}=="0451",ATTRS{idProduct}=="16a8", SYMLINK+="ttyUSB99", GROUP="dialout", MODE="0666"

/etc/defaults/openhab2 is adjusted as well:

EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB99:/dev/bluegiga0:/dev/bluegiga1:/dev/bluegiga2:/dev/bluegiga3:/dev/bluegiga4"

If it’s the only serial device, then it works:

2018-07-09 15:14:41.926 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_cc2531:88c83f29' changed from UNINITIALIZED to INITIALIZING
2018-07-09 15:14:41.936 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_cc2531:88c83f29' changed from INITIALIZING to UNKNOWN
2018-07-09 15:14:41.942 [hingStatusInfoChangedEvent] - 'zigbee:device:88c83f29:00158d000243776c' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2018-07-09 15:14:41.944 [hingStatusInfoChangedEvent] - 'zigbee:device:88c83f29:00158d000243776c' changed from INITIALIZING to OFFLINE
2018-07-09 15:14:46.804 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_cc2531:88c83f29' changed from UNKNOWN to ONLINE

But if some Bluegiga BLE dongles are connected to the system as well, the binding can’t open the serial port:

2018-07-09 15:00:12.061 [ERROR] [ding.zigbee.handler.ZigBeeSerialPort] - Serial Error: Port /dev/ttyUSB99 does not exist.
2018-07-09 15:00:12.061 [ERROR] [.cc2531.network.ZigBeeNetworkManager] - Failed to open the dongle.

btw: The Bluegiga-dongles are symlinked to /dev/bluegiga0, /dev/bluegiga1 etc.

More than this: When I remove a CC2531 coordinator from the paper UI and add it back again, it only offers a wrong serial port (/dev/bluegiga1) in the drop-down list to me:

Since the field is not editable, I cannot adjust to the /dev/ttyUSB99 in that case.

Any idea what’s wrong here?

As I said, plug in the CC2531 first, start openHAB and then plug the Bluegigas later works. But this is not a solution for daily operation. And I should have mitigated this need by the symlinking stuff …

[curlyel]

I did some more tests. Looks to me now, that I likely need look more on the Bluetooth binding for that issue.
I’ve asked it’s maintainer @vkolotov as well:

3rd Party Bluetooth Binding. Beta testers needed

Hi @vkolotov, I’m currently playing with a couple of Bluegiga dongles connected to your binding: 216 │ Active │ 80 │ 1.2.2 │ org.sputnikdev:org.eclipse.smarthome.binding.bluetooth.transport.bluegiga 220 │ Active │ 80 │ 1.1.5 │ org.sputnikdev:org.eclipse.smarthome.binding.bluetooth I’ve just discovered some odd behaviour at startup which seems to block other serial ports (a Zigbee dongle in my case). I’ve already asked the maintainer of the Zigbee bindin…

Sorry for noise. But I leave it though - just for reference

[Kim_Andersen]

Isn´t the Philips hue sensor applied fully into the binding 2.3.0 stable?

I have just added this device to my Zigbee network, but the switch for motion doesn´t seem to work. It´s stated ‘Undefined’.
Illumiance, temprature and Occupancy is working just fine…

Screenshot from PaperUI:

My item file:

Switch 	Stue_HUE_Motion		"Hue sensor motion [%s]"		<cum_motion>				{ channel="zigbee:device:6ec05458:0017880102139d00:0017880102139D00_1_switch_onoff" }
Number	Stue_HUE_Temp 		"Hue sensor temperatur [%.1f °C]"	<cu_heating>	(Temperatur)		{ channel="zigbee:device:6ec05458:0017880102139d00:0017880102139D00_2_measurement_temperature" }
Number	Stue_HUE_illumiance 	"Hue sensor Ilumiance [%s]"		<light>					{ channel="zigbee:device:6ec05458:0017880102139d00:0017880102139D00_2_measurement_illuminance" }
Switch 	Stue_HUE_Occu		"Hue sensor Occupancy [%s]"		<cum_motion>				{ channel="zigbee:device:6ec05458:0017880102139d00:0017880102139D00_2_sensor_occupancy" }

Screenshot from BasicUI:

Nothing from the motionsensor But the other channels are working just fine. A few minutes ago it worked just fine from the Hue gateway. I just removed it fra Hue setup, reset it, and added it to my Zigbee controller insted.

[scottk (Scott Karns)]

Kim, I’m not sure what the Switch channel is, it does nothing that I can detect on my Philips motion detector. The Occupancy channel indicates when motion is detected.

[chris (Chris Jackson)]

@scottk

I’m not sure what the Switch channel is

I suspect it’s fundamentally not used. I believe it’s there to allow control of other devices directly - the binding of course doesn’t know this so it just shows all available channels.

[Kim_Andersen]

Hmm, I didnt think the motion sensor would be the Occupancy switch. I dont believe it´s registrering motions like it use to. But I´ll test it more later.

[chris (Chris Jackson)]

Please consider that the binding will present ALL channels that it thinks the device supports - it does not mean the device supports them! The binding detects the features from the device, and then provides channels. In the case of this device, there are a few channels that are provided and some, like this switch, are not used. It’s as I said in my earlier message.

This switch is there to allow controlling other device (ie lights) directly - you can’t use this so I suggest to ignore it.

[novoplan (Joe)]

Hi,

i have a Telegesis ETRX3 Dongle (long range).
Now i try to connect to a hue bulb (LTR001). I did a reset on the bulb with the philips dimmer and the discovery of the zigbee binding shows me the bulb. After adding the bulb as a thing the status says “Offline”.
The bulb is a about 4 meters away from the dongle with direct view connection.
What can i do?

2018-07-14 19:27:43.550 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0017880103E631B0: Starting ZigBee device discovery

2018-07-14 19:27:43.552 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0017880100FF64A9: Starting ZigBee device discovery

2018-07-14 19:27:43.563 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:04000A33:0017880103e631b0' to inbox.

2018-07-14 19:27:43.573 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:04000A33:0017880100ff64a9' to inbox.

==> /var/log/openhab2/events.log <==

2018-07-14 19:27:43.594 [home.event.InboxAddedEvent] - Discovery Result with UID 'zigbee:device:04000A33:0017880103e631b0' has been added.

2018-07-14 19:27:43.616 [home.event.InboxAddedEvent] - Discovery Result with UID 'zigbee:device:04000A33:0017880100ff64a9' has been added.

2018-07-14 19:28:27.094 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zigbee:device:04000A33:0017880100ff64a9' has been removed.

2018-07-14 19:28:27.147 [hingStatusInfoChangedEvent] - 'zigbee:device:04000A33:0017880100ff64a9' changed from UNINITIALIZED to INITIALIZING

2018-07-14 19:28:27.163 [hingStatusInfoChangedEvent] - 'zigbee:device:04000A33:0017880100ff64a9' changed from INITIALIZING to OFFLINE

2018-07-14 19:28:27.205 [me.event.ThingUpdatedEvent] - Thing 'zigbee:device:04000A33:0017880100ff64a9' has been updated.

2018-07-14 19:28:27.209 [nt.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:04000A33:0017880100ff64a9 changed to UNKNOWN.

[Kim_Andersen]

I simply cant get this Hue motion sensor to work.
First time included, there are no motion, but temperature and illumination seemed to work. I then removed it and included it again, and now nothing seems to work (update value), except temperature, which is showen but not updating.

[chris (Chris Jackson)]

Please use debug logging to see what is happening.

[Kim_Andersen]

I will, but it doesn´t really say anything…
Seems like both the Philips Dimmer Switch (which is stated offline) and the Philips motion sensor have no communication with the Elelabs Rpi shield (Zigbee controller).

Here is the log…
I startet a manual scan for devices at 19:38:22

2018-07-15 19:33:09.117 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

2018-07-15 19:33:24.030 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 000D6F000FA0C316: Discovery notification

2018-07-15 19:33:24.038 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.

2018-07-15 19:33:24.295 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.

2018-07-15 19:34:11.451 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

2018-07-15 19:35:13.787 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

2018-07-15 19:36:16.122 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

2018-07-15 19:37:18.457 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

2018-07-15 19:38:20.791 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

2018-07-15 19:38:22.807 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_ember:6ec05458

2018-07-15 19:38:22.812 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.

2018-07-15 19:38:22.816 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=24, permitDuration=60, tcSignificance=true]

2018-07-15 19:38:22.820 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, sequence=36, payload=00 3C 01]

2018-07-15 19:38:22.823 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendBroadcastRequest [destination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=36], radius=31, messageTag=36, messageContents=00 3C 01]

2018-07-15 19:38:22.827 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue: 1

2018-07-15 19:38:22.830 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspSendBroadcastRequest [destination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=36], radius=31, messageTag=36, messageContents=00 3C 01]

2018-07-15 19:38:22.834 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=0, ackNum=4, reTx=false, data=24 00 FF 00 36 FC FF 00 00 36 00 00 00 40 11 00 00 24 1F 24 03 00 3C 01]

2018-07-15 19:38:22.838 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=25, permitDuration=60, tcSignificance=true]

2018-07-15 19:38:22.842 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, sequence=37, payload=00 3C 01]

2018-07-15 19:38:22.846 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=37], messageTag=37, messageContents=00 3C 01]

2018-07-15 19:38:22.849 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue: 1

2018-07-15 19:38:22.952 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=1, reTx=false, data=24 80 FF 00 36 00 3C]

2018-07-15 19:38:22.955 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=0, ackNum=4, reTx=false, data=24 00 FF 00 36 FC FF 00 00 36 00 00 00 40 11 00 00 24 1F 24 03 00 3C 01]

2018-07-15 19:38:22.957 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=60]

2018-07-15 19:38:22.959 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=60]

2018-07-15 19:38:22.960 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=60]

2018-07-15 19:38:22.962 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]

2018-07-15 19:38:22.965 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=37], messageTag=37, messageContents=00 3C 01]

2018-07-15 19:38:22.968 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=1, ackNum=5, reTx=false, data=25 00 FF 00 34 00 00 00 00 00 36 00 00 00 40 11 00 00 25 25 03 00 3C 01]

2018-07-15 19:38:22.973 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=1, reTx=false, data=24 90 FF 00 45 05 00 00 36 00 00 00 00 01 00 00 3C FF 00 00 00 FF FF 03 00 3C 01]

2018-07-15 19:38:22.976 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=60], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]

2018-07-15 19:38:22.979 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=60], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]

2018-07-15 19:38:22.982 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=null, radius=0, sequence=36, payload=00 3C 01]

2018-07-15 19:38:22.985 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=NULL, permitDuration=60, tcSignificance=true]

2018-07-15 19:38:22.989 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]

2018-07-15 19:38:23.024 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery scheduled [NEIGHBORS, ROUTES]

2018-07-15 19:38:23.028 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0017880102139D00: Node SVC Discovery already scheduled or running

2018-07-15 19:38:23.098 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=2, reTx=false, data=25 80 FF 00 34 00 3D]

2018-07-15 19:38:23.102 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=1, ackNum=5, reTx=false, data=25 00 FF 00 34 00 00 00 00 00 36 00 00 00 40 11 00 00 25 25 03 00 3C 01]

2018-07-15 19:38:23.105 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=61]

2018-07-15 19:38:23.115 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=61]

2018-07-15 19:38:23.118 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=61]

2018-07-15 19:38:23.129 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]

2018-07-15 19:38:23.142 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=2, reTx=false, data=25 90 FF 00 45 00 00 00 36 00 00 00 40 01 00 00 3D FF 00 00 00 FF FF 03 00 3C 01]

2018-07-15 19:38:23.146 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=61], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]

2018-07-15 19:38:23.151 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=61], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]

2018-07-15 19:38:23.155 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=null, radius=0, sequence=37, payload=00 3C 01]

2018-07-15 19:38:23.158 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=NULL, permitDuration=60, tcSignificance=true]

2018-07-15 19:38:23.161 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]

2018-07-15 19:38:23.167 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=2, reTx=false, data=25 90 FF 00 45 00 00 00 36 80 00 00 40 01 00 00 3E FF 00 00 00 FF FF 02 00 00]

2018-07-15 19:38:23.171 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32822, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=62], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]

2018-07-15 19:38:23.174 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32822, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=62], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]

2018-07-15 19:38:23.177 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, sequence=37, payload=00 00]

2018-07-15 19:38:23.180 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS]

2018-07-15 19:38:23.183 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]

2018-07-15 19:38:23.186 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=2, reTx=false, data=25 90 FF 00 3F 00 00 00 00 00 36 00 00 00 40 11 00 00 3D 25 00 00]

2018-07-15 19:38:23.188 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=61], messageTag=37, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:23.190 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=61], messageTag=37, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:23.191 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=61], messageTag=37, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:23.193 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]

2018-07-15 19:38:23.898 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=2, reTx=false, data=25 90 FF 00 3F 06 FC FF 00 00 36 00 00 00 00 01 00 00 3C 24 00 00]

2018-07-15 19:38:23.903 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=60], messageTag=36, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:23.907 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=60], messageTag=36, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:23.911 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=60], messageTag=36, status=EMBER_SUCCESS, messageContents=]

[Kim_Andersen]

Log continue:

2018-07-15 19:38:23.914 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]

2018-07-15 19:38:24.626 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery running

2018-07-15 19:38:24.630 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=26, startIndex=0]

2018-07-15 19:38:24.633 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, sequence=38, payload=00 00]

2018-07-15 19:38:24.661 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=38], messageTag=38, messageContents=00 00]

2018-07-15 19:38:24.663 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue: 1

2018-07-15 19:38:24.666 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=38], messageTag=38, messageContents=00 00]

2018-07-15 19:38:24.670 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=2, ackNum=3, reTx=false, data=26 00 FF 00 34 00 00 00 00 00 31 00 00 00 40 11 00 00 26 26 02 00 00]

2018-07-15 19:38:24.799 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=3, reTx=false, data=26 80 FF 00 34 00 3F]

2018-07-15 19:38:24.802 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=2, ackNum=3, reTx=false, data=26 00 FF 00 34 00 00 00 00 00 31 00 00 00 40 11 00 00 26 26 02 00 00]

2018-07-15 19:38:24.806 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=63]

2018-07-15 19:38:24.810 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=63]

2018-07-15 19:38:24.814 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=63]

2018-07-15 19:38:24.817 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]

2018-07-15 19:38:24.822 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=3, reTx=false, data=26 90 FF 00 45 00 00 00 31 00 00 00 40 01 00 00 3F FF 00 00 00 FF FF 02 00 00]

2018-07-15 19:38:24.825 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=63], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]

2018-07-15 19:38:24.828 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=63], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]

2018-07-15 19:38:24.830 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=null, radius=0, sequence=38, payload=00 00]

2018-07-15 19:38:24.833 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=NULL, startIndex=0]

2018-07-15 19:38:24.838 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]

2018-07-15 19:38:24.842 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=3, reTx=false, data=26 90 FF 00 45 00 00 00 31 80 00 00 40 01 00 00 40 FF 00 00 00 FF FF 05 00 00 00 00 00]

2018-07-15 19:38:24.845 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32817, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=64], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 00 00 00]

2018-07-15 19:38:24.847 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32817, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=64], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 00 00 00]

2018-07-15 19:38:24.850 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, sequence=38, payload=00 00 00 00 00]

2018-07-15 19:38:24.852 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]

2018-07-15 19:38:24.855 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]

2018-07-15 19:38:24.856 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]]

2018-07-15 19:38:24.859 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=3, reTx=false, data=26 90 FF 00 3F 00 00 00 00 00 31 00 00 00 40 11 00 00 3F 26 00 00]

2018-07-15 19:38:24.859 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000FA0C316: Neighbor table unchanged

2018-07-15 19:38:24.861 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=63], messageTag=38, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:24.863 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=63], messageTag=38, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:24.863 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery request NEIGHBORS successful. Advanced to ROUTES.

2018-07-15 19:38:24.864 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=63], messageTag=38, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:24.866 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]

2018-07-15 19:38:24.870 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery running

2018-07-15 19:38:24.872 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=27, startIndex=0]

2018-07-15 19:38:24.875 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, sequence=39, payload=00 00]

2018-07-15 19:38:24.877 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=39], messageTag=39, messageContents=00 00]

2018-07-15 19:38:24.880 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue: 1

2018-07-15 19:38:24.882 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=39], messageTag=39, messageContents=00 00]

2018-07-15 19:38:24.885 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=3, ackNum=7, reTx=false, data=27 00 FF 00 34 00 00 00 00 00 32 00 00 00 40 11 00 00 27 27 02 00 00]

2018-07-15 19:38:25.027 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=4, reTx=false, data=27 80 FF 00 34 00 41]

2018-07-15 19:38:25.030 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=3, ackNum=7, reTx=false, data=27 00 FF 00 34 00 00 00 00 00 32 00 00 00 40 11 00 00 27 27 02 00 00]

2018-07-15 19:38:25.031 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=65]

2018-07-15 19:38:25.033 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=65]

2018-07-15 19:38:25.035 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=65]

2018-07-15 19:38:25.037 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]

2018-07-15 19:38:25.040 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=4, reTx=false, data=27 90 FF 00 45 00 00 00 32 00 00 00 40 01 00 00 41 FF 00 00 00 FF FF 02 00 00]

2018-07-15 19:38:25.043 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=65], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]

2018-07-15 19:38:25.045 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=65], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]

2018-07-15 19:38:25.047 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, sequence=39, payload=00 00]

2018-07-15 19:38:25.049 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=0]

2018-07-15 19:38:25.056 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]

2018-07-15 19:38:25.061 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=4, reTx=false, data=27 90 FF 00 45 00 00 00 32 80 00 00 40 01 00 00 42 FF 00 00 00 FF FF 50 00 00 10 00 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]

2018-07-15 19:38:25.064 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=66], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 00 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]

2018-07-15 19:38:25.067 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=66], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 00 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]

2018-07-15 19:38:25.070 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=39, payload=00 00 10 00 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]

2018-07-15 19:38:25.073 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=0, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]

2018-07-15 19:38:25.076 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]

2018-07-15 19:38:25.078 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=4, reTx=false, data=27 90 FF 00 3F 00 00 00 00 00 32 00 00 00 40 11 00 00 41 27 00 00]

2018-07-15 19:38:25.080 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=65], messageTag=39, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:25.080 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=0, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]

2018-07-15 19:38:25.081 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=65], messageTag=39, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:25.083 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=28, startIndex=15]

2018-07-15 19:38:25.093 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, sequence=40, payload=00 0F]

2018-07-15 19:38:25.095 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=40], messageTag=40, messageContents=00 0F]

2018-07-15 19:38:25.097 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue: 1

2018-07-15 19:38:25.099 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=40], messageTag=40, messageContents=00 0F]

2018-07-15 19:38:25.101 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=2, reTx=false, data=28 00 FF 00 34 00 00 00 00 00 32 00 00 00 40 11 00 00 28 28 02 00 0F]

2018-07-15 19:38:25.103 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=65], messageTag=39, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:25.105 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]

2018-07-15 19:38:25.230 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=5, reTx=false, data=28 80 FF 00 34 00 43]

2018-07-15 19:38:25.232 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=4, ackNum=2, reTx=false, data=28 00 FF 00 34 00 00 00 00 00 32 00 00 00 40 11 00 00 28 28 02 00 0F]

2018-07-15 19:38:25.233 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=67]

2018-07-15 19:38:25.235 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=67]

2018-07-15 19:38:25.236 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=67]

2018-07-15 19:38:25.238 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]

2018-07-15 19:38:25.240 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=5, reTx=false, data=28 90 FF 00 45 00 00 00 32 00 00 00 40 01 00 00 43 FF 00 00 00 FF FF 02 00 0F]

2018-07-15 19:38:25.242 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=67], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 0F]

2018-07-15 19:38:25.246 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=67], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 0F]

2018-07-15 19:38:25.247 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, sequence=40, payload=00 0F]

2018-07-15 19:38:25.249 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=15]

2018-07-15 19:38:25.256 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]

2018-07-15 19:38:25.259 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=5, reTx=false, data=28 90 FF 00 45 00 00 00 32 80 00 00 40 01 00 00 44 FF 00 00 00 FF FF 0A 00 00 10 0F 01 00 00 03 00 00]

2018-07-15 19:38:25.266 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=68], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 0F 01 00 00 03 00 00]

2018-07-15 19:38:25.268 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=68], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 0F 01 00 00 03 00 00]

2018-07-15 19:38:25.271 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=40, payload=00 00 10 0F 01 00 00 03 00 00]

2018-07-15 19:38:25.273 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]

2018-07-15 19:38:25.276 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]

2018-07-15 19:38:25.276 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]

2018-07-15 19:38:25.279 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000FA0C316: Routing table NEW: [RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]

2018-07-15 19:38:25.281 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000FA0C316: Routing table OLD: [RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]

2018-07-15 19:38:25.282 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=5, reTx=false, data=28 90 FF 00 3F 00 00 00 00 00 32 00 00 00 40 11 00 00 43 28 00 00]

2018-07-15 19:38:25.284 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=67], messageTag=40, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:25.284 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000FA0C316: Routing table unchanged

2018-07-15 19:38:25.286 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=67], messageTag=40, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:25.287 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery request ROUTES successful. Advanced to null.

2018-07-15 19:38:25.288 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=67], messageTag=40, status=EMBER_SUCCESS, messageContents=]

2018-07-15 19:38:25.289 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery running

2018-07-15 19:38:25.290 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]

2018-07-15 19:38:25.293 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000FA0C316: Node SVC Discovery complete

2018-07-15 19:38:25.297 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000FA0C316: Node 0 update

2018-07-15 19:38:25.303 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 000D6F000FA0C316: Discovery notification

2018-07-15 19:38:25.310 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.

2018-07-15 19:38:25.524 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.

2018-07-15 19:39:23.127 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: 
Polling...

[Kim_Andersen]

And the polling just continue without any respond.

2018-07-15 19:50:48.812 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...
2018-07-15 19:51:51.147 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...
2018-07-15 19:52:53.482 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

[Kim_Andersen]

Hmm, i think there are some problems located last in the log sequence:

2018-07-15 20:05:21.502 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

2018-07-15 20:05:47.275 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0017880102139D00: Node SVC Discovery running

2018-07-15 20:05:47.277 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 51573/0, cluster=0031, TID=3A, startIndex=0]

2018-07-15 20:05:47.280 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=51573/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, sequence=58, payload=00 00]

2018-07-15 20:05:47.282 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=51573, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=58], messageTag=58, messageContents=00 00]

2018-07-15 20:05:47.284 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue: 1

2018-07-15 20:05:47.286 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=51573, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=58], messageTag=58, messageContents=00 00]

2018-07-15 20:05:47.289 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=6, ackNum=7, reTx=false, data=3A 00 FF 00 34 00 75 C9 00 00 31 00 00 00 40 11 00 00 3A 3A 02 00 00]

2018-07-15 20:05:47.401 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=7, reTx=false, data=3A 80 FF 00 34 00 65]

2018-07-15 20:05:47.405 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=6, ackNum=7, reTx=false, data=3A 00 FF 00 34 00 75 C9 00 00 31 00 00 00 40 11 00 00 3A 3A 02 00 00]

2018-07-15 20:05:47.407 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=101]

2018-07-15 20:05:47.410 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=101]

2018-07-15 20:05:47.412 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=101]

2018-07-15 20:05:47.414 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]

2018-07-15 20:05:52.098 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=7, reTx=false, data=3A 90 FF 00 3F 00 75 C9 00 00 31 00 00 00 40 10 00 00 65 3A 66 00]

2018-07-15 20:05:52.102 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=51573, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=101], messageTag=58, status=EMBER_DELIVERY_FAILED, messageContents=]

2018-07-15 20:05:52.106 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=51573, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=101], messageTag=58, status=EMBER_DELIVERY_FAILED, messageContents=]

2018-07-15 20:05:52.109 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=51573, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=101], messageTag=58, status=EMBER_DELIVERY_FAILED, messageContents=]

2018-07-15 20:05:52.113 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]

2018-07-15 20:05:57.293 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0017880102139D00: Node SVC Discovery ManagementLqiRequest response CommandResult [TIMEOUT]

2018-07-15 20:05:57.299 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0017880102139D00: Node SVC Discovery request NEIGHBORS failed. Retry 325, wait 230928ms before retry.

2018-07-15 20:06:23.840 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102139D00: Polling...

[Kim_Andersen]

@chris
Did you see the log entries above?

[chris (Chris Jackson)]

@Kim_Andersen

Did you see the log entries above?

Yes, but I was quite busy yesterday so did not have the chance to look at them. I’ll try and take a look tonight - it would probably be good in future to keep the logs as a single attachment, and then post them on a site somewhere (eg dropbox, github, …).