Zigbee discovery

Jose90 · July 26, 2017, 2:47am

Hello,

Currently I am trying to connect my hue bulbs to openhab by using cc2531 usb dongle as a coordinator.
After the successful installation of openhab stable version on the raspberry pi, I flash the CC2531ZNP-Pro-Secure_Standard.hex to
the cc2531 with flash programmer. Then I installed the Zigbee addon through paper UI, and added cc2531 coordinator
to thing list. The problem is I can not discover any device on paper UI. From monitoring the Sniffer program, the hue bulbs seems to send out beacon request.
I am new to openhab, can someone please help me with this issue? Here is the deug log:

2017-07-25 17:15:35.280 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_cc2531:6c91b58b].
2017-07-25 17:15:35.284 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel 11.0
2017-07-25 17:15:35.287 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID -2.0
2017-07-25 17:15:35.294 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID 00124B000E0D7EFC
2017-07-25 17:15:35.300 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key 4F 04 E8 F7 67 E2 17 9F 5A 56 7D 51 3E 65 C3 15
2017-07-25 17:15:35.302 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key String 4F 04 E8 F7 67 E2 17 9F 5A 56 7D 51 3E 65 C3 15
2017-07-25 17:15:35.304 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key array [79, 4, 232, 247, 103, 226, 23, 159, 90, 86, 125, 81, 62, 101, 195, 21]
2017-07-25 17:15:35.305 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key final array [79, 4, 232, 247, 103, 226, 23, 159, 90, 86, 125, 81, 62, 101, 195, 21]
2017-07-25 17:15:35.363 [DEBUG] [ndler.ZigBeeCoordinatorCC2531Handler] - ZigBee Coordinator ZNP opening Port:'/dev/ttyACM0' PAN:fffffffe, Channel:11
2017-07-25 17:15:35.371 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
2017-07-25 17:15:36.374 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2017-07-25 17:15:36.375 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2017-07-25 17:15:36.388 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Creating ZigBee discovery service for zigbee:coordinator_cc2531:6c91b58b
2017-07-25 17:15:36.390 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Activating ZigBee discovery service for zigbee:coordinator_cc2531:6c91b58b
2017-07-25 17:15:36.404 [DEBUG] [org.openhab.binding.zigbee          ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=888, service.bundleid=185, service.scope=singleton} - org.openhab.binding.zigbee
2017-07-25 17:15:36.470 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key initialise [79, 4, 232, 247, 103, 226, 23, 159, 90, 86, 125, 81, 62, 101, 195, 21]
2017-07-25 17:15:36.472 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - CC2531 transport initialize
2017-07-25 17:15:36.480 [DEBUG] [ndler.ZigBeeCoordinatorCC2531Handler] - Opening ZigBee CC2531 serial port
2017-07-25 17:15:36.482 [DEBUG] [ndler.ZigBeeCoordinatorCC2531Handler] - Connecting to serial port [/dev/ttyACM0]
2017-07-25 17:15:36.615 [INFO ] [ndler.ZigBeeCoordinatorCC2531Handler] - Serial port [/dev/ttyACM0] is initialized.
2017-07-25 17:15:36.642 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  SYS_RESET (Packet: subsystem=null, length=1, apiId=41 00, data=FE 01 41 00 01 41, checksum=41, error=false) 
2017-07-25 17:15:37.254 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.51.247:8080
2017-07-25 17:15:37.259 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.51.247:8443
2017-07-25 17:15:37.732 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- SYS_RESET_RESPONSE (FE 06 41 80 00 02 00 02 06 03 C2)
2017-07-25 17:15:37.737 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=6, apiId=41 80, data=FE 06 41 80 00 02 00 02 06 03 C2, checksum=C2, error=false
2017-07-25 17:15:37.742 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  SYS_VERSION (Packet: subsystem=null, length=0, apiId=21 02, data=FE 00 21 02 23, checksum=23, error=false) 
2017-07-25 17:15:37.754 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  SYS_VERSION_RESPONSE (FE 05 61 02 02 00 02 06 03 63)
2017-07-25 17:15:37.760 [DEBUG] [etwork.impl.ZigBeeNetworkManagerImpl] - CC2531 version is Software=2.6 Product=0 Hardware=3 Transport=2
2017-07-25 17:15:37.763 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - initResponse is JOINED
2017-07-25 17:15:37.766 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - initializeNetwork is false
2017-07-25 17:15:37.769 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 05 24, checksum=24, error=false) 
2017-07-25 17:15:37.779 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 05 0B 00 00 00 00 00 00 00 67)
2017-07-25 17:15:37.781 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 06 27, checksum=27, error=false) 
2017-07-25 17:15:37.790 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 06 10 CF 00 00 00 00 00 00 B0)
2017-07-25 17:15:37.793 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 07 26, checksum=26, error=false) 
2017-07-25 17:15:37.803 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 07 FC 7E 0D 0E 00 4B 12 00 B6)
2017-07-25 17:15:37.805 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - CC2531 transport startup
2017-07-25 17:15:37.807 [DEBUG] [etwork.impl.ZigBeeNetworkManagerImpl] - Creating network as Coordinator
2017-07-25 17:15:37.808 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  ZDO_MSG_CB_REGISTER (Packet: subsystem=null, length=2, apiId=25 3E, data=FE 02 25 3E FF FF 19, checksum=19, error=false) 
2017-07-25 17:15:37.819 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  ZDO_MSG_CB_REGISTER_SRSP (FE 01 65 3E 00 5A)
2017-07-25 17:15:37.824 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=3, apiId=26 05, data=FE 03 26 05 8F 01 01 AF, checksum=AF, error=false) 
2017-07-25 17:15:37.841 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
2017-07-25 17:15:37.843 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  ZDO_STARTUP_FROM_APP (Packet: subsystem=null, length=2, apiId=25 40, data=FE 02 25 40 00 00 67, checksum=67, error=false) 
2017-07-25 17:15:38.211 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2017-07-25 17:15:38.374 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2017-07-25 17:15:38.578 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2017-07-25 17:15:38.643 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  ZDO_STARTUP_FROM_APP_SRSP (FE 01 65 40 00 24)
2017-07-25 17:15:38.648 [INFO ] [etwork.impl.ZigBeeNetworkManagerImpl] - Initialized ZigBee network with existing network state.
2017-07-25 17:15:38.658 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZDO_STATE_CHANGE_IND (FE 01 45 C0 09 8D)
2017-07-25 17:15:38.659 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: ZDO_STATE_CHANGE_IND{State=DEV_COORD_STARTED}
2017-07-25 17:15:38.662 [DEBUG] [etwork.impl.ZigBeeNetworkManagerImpl] - Started as ZigBee Coordinator
2017-07-25 17:15:38.667 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45c0
2017-07-25 17:15:38.706 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_REGISTER (Packet: subsystem=null, length=9, apiId=24 00, data=FE 09 24 00 01 04 01 00 00 00 00 00 00 29, checksum=29, error=false) 
2017-07-25 17:15:38.723 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_REGISTER_SRSP (FE 01 64 00 00 65)
2017-07-25 17:15:38.725 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Registered endpoint 1 with profile: 260
2017-07-25 17:15:38.727 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Scheduling node discovery
2017-07-25 17:15:38.748 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Starting node discovery
2017-07-25 17:15:38.748 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - Starting mesh update task with interval of 60 seconds
2017-07-25 17:15:38.758 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 05 24, checksum=24, error=false) 
2017-07-25 17:15:38.768 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 05 0B 06 00 FF FE 01 64 00 05)
2017-07-25 17:15:38.769 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 07 26, checksum=26, error=false) 
2017-07-25 17:15:38.782 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=00, nwkAddrOfInterest=0, requestType=1, startIndex=0]
2017-07-25 17:15:38.787 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 07 FC 7E 0D 0E 00 4B 12 00 B6)
2017-07-25 17:15:38.790 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialise done....... 11  -12528  00124B000E0D7EFC
2017-07-25 17:15:38.896 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2017-07-25 17:15:38.939 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=15, apiId=24 01, data=FE 0F 24 01 00 00 00 00 01 00 00 30 1F 05 00 00 00 01 00 00, checksum=00, error=false) 
2017-07-25 17:15:39.011 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:15:39.013 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 81 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 00 11)
2017-07-25 17:15:39.019 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 81, data=FE 0D 45 81 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 00 11, checksum=11, error=false
2017-07-25 17:15:39.228 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00124B000E0D7EFC, nwkAddrRemoteDev=0, numAssocDev=0, startIndex=null, nwkAddrAssocDevList=[]]
2017-07-25 17:15:39.254 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Discovery request IEEE_ADDRESS successfull. Advanced to NODE_DESCRIPTOR.
2017-07-25 17:15:39.258 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NodeDescriptorRequest [0/0 -> 0/0, cluster=0002, TID=01, nwkAddrOfInterest=0]
2017-07-25 17:15:39.269 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 F6)
2017-07-25 17:15:39.269 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 00 00 00 00 02 00 01 30 1F 03 00 00 00 07, checksum=07, error=false) 
2017-07-25 17:15:39.270 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=21, apiId=45 FF, data=FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 F6, checksum=F6, error=false
2017-07-25 17:15:39.274 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00124B000E0D7EFC, nwkAddrRemoteDev=0, numAssocDev=0, startIndex=null, nwkAddrAssocDevList=[]]
2017-07-25 17:15:39.323 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:15:39.326 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 12 45 82 00 00 00 00 00 00 40 8F 00 00 50 A0 00 01 00 A0 00 00 4B)
2017-07-25 17:15:39.328 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=18, apiId=45 82, data=FE 12 45 82 00 00 00 00 00 00 40 8F 00 00 50 A0 00 01 00 A0 00 00 4B, checksum=4B, error=false
2017-07-25 17:15:39.355 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NodeDescriptorResponse [0/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=0, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=80, complexDescriptorAvailable=false, manufacturerCode=0, logicalType=COORDINATOR, serverCapabilities=[PRIMARY_TRUST_CENTER], incomingTransferSize=160, outgoingTransferSize=160, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[MAINS_POWER, RECEIVER_ON_WHEN_IDLE, ALTERNATIVE_PAN, FULL_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false]]
2017-07-25 17:15:39.369 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Discovery request NODE_DESCRIPTOR successfull. Advanced to POWER_DESCRIPTOR.
2017-07-25 17:15:39.371 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 19 45 FF 00 00 00 02 80 00 00 00 00 00 00 00 00 40 8F 00 00 50 A0 00 01 00 A0 00 00 BF)
2017-07-25 17:15:39.390 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=25, apiId=45 FF, data=FE 19 45 FF 00 00 00 02 80 00 00 00 00 00 00 00 00 40 8F 00 00 50 A0 00 01 00 A0 00 00 BF, checksum=BF, error=false
2017-07-25 17:15:39.380 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 0/0, cluster=0003, TID=02, nwkAddrOfInterest=0]
2017-07-25 17:15:39.394 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NodeDescriptorResponse [0/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=0, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=80, complexDescriptorAvailable=false, manufacturerCode=0, logicalType=COORDINATOR, serverCapabilities=[PRIMARY_TRUST_CENTER], incomingTransferSize=160, outgoingTransferSize=160, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[MAINS_POWER, RECEIVER_ON_WHEN_IDLE, ALTERNATIVE_PAN, FULL_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false]]
2017-07-25 17:15:39.394 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 00 00 00 00 03 00 02 30 1F 03 00 00 00 05, checksum=05, error=false) 
2017-07-25 17:15:39.438 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:15:39.449 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 07 45 83 00 00 00 00 00 10 C1 10)
2017-07-25 17:15:39.450 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=7, apiId=45 83, data=FE 07 45 83 00 00 00 00 00 10 C1 10, checksum=10, error=false
2017-07-25 17:15:39.459 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: PowerDescriptorResponse [0/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=0, powerDescriptor=RECEIVER_ON_IDLE, [MAINS], MAINS, FULL]
2017-07-25 17:15:39.478 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Discovery request POWER_DESCRIPTOR successfull. Advanced to ACTIVE_ENDPOINTS.
2017-07-25 17:15:39.479 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0E 45 FF 00 00 00 03 80 00 00 00 00 00 00 00 10 C1 E6)
2017-07-25 17:15:39.480 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 0/0, cluster=0005, TID=03, nwkAddrOfInterest=0]
2017-07-25 17:15:39.481 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=14, apiId=45 FF, data=FE 0E 45 FF 00 00 00 03 80 00 00 00 00 00 00 00 10 C1 E6, checksum=E6, error=false
2017-07-25 17:15:39.482 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 00 00 00 00 05 00 03 30 1F 03 00 00 00 02, checksum=02, error=false) 
2017-07-25 17:15:39.483 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: PowerDescriptorResponse [0/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=0, powerDescriptor=RECEIVER_ON_IDLE, [MAINS], MAINS, FULL]
2017-07-25 17:15:39.505 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:15:39.510 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 07 45 85 00 00 00 00 00 01 01 C7)
2017-07-25 17:15:39.512 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=7, apiId=45 85, data=FE 07 45 85 00 00 00 00 00 01 01 C7, checksum=C7, error=false
2017-07-25 17:15:39.517 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [0/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=0, activeEpCnt=1, activeEpList=[1]]
2017-07-25 17:15:39.519 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0/1: Scheduling device discovery
2017-07-25 17:15:39.524 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0E 45 FF 00 00 00 05 80 00 00 00 00 00 00 00 01 01 31)
2017-07-25 17:15:39.525 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=14, apiId=45 FF, data=FE 0E 45 FF 00 00 00 05 80 00 00 00 00 00 00 00 01 01 31, checksum=31, error=false
2017-07-25 17:15:39.528 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [0/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=0, activeEpCnt=1, activeEpList=[1]]
2017-07-25 17:15:39.530 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Discovery request ACTIVE_ENDPOINTS successfull. Advanced to IEEE_ADDRESS.
2017-07-25 17:15:39.531 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Ending node discovery
2017-07-25 17:15:39.536 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0/1: Starting device discovery
2017-07-25 17:15:39.540 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 0/0, cluster=0004, TID=04, nwkAddrOfInterest=0, endpoint=1]
2017-07-25 17:15:39.543 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 00 00 00 00 04 00 04 30 1F 04 00 00 00 01 01, checksum=01, error=false) 
2017-07-25 17:15:39.601 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:15:39.604 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0E 45 84 00 00 00 00 00 08 01 04 01 00 00 00 00 00 C3)
2017-07-25 17:15:39.605 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=14, apiId=45 84, data=FE 0E 45 84 00 00 00 00 00 08 01 04 01 00 00 00 00 00 C3, checksum=C3, error=false
2017-07-25 17:15:39.610 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [0/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=0, length=8, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=260, deviceId=0, deviceVersion=0, inputClusterList=[], outputClusterList=[]]]
2017-07-25 17:15:39.617 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 15 45 FF 00 00 00 04 80 00 00 00 00 00 00 00 08 01 04 01 00 00 00 00 00 27)
2017-07-25 17:15:39.640 [DEBUG] [om.zsmartsystems.zigbee.ZigBeeDevice] - 0/1: Setting input clusters []
2017-07-25 17:15:39.641 [DEBUG] [om.zsmartsystems.zigbee.ZigBeeDevice] - 0/1: Setting output clusters []
2017-07-25 17:15:39.645 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=21, apiId=45 FF, data=FE 15 45 FF 00 00 00 04 80 00 00 00 00 00 00 00 08 01 04 01 00 00 00 00 00 27, checksum=27, error=false
2017-07-25 17:15:39.650 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B000E0D7EFC: Node 0 is added to the network
2017-07-25 17:15:39.652 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [0/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=0, length=8, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=260, deviceId=0, deviceVersion=0, inputClusterList=[], outputClusterList=[]]]
2017-07-25 17:15:39.654 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee Node discovered: IEEE=00124B000E0D7EFC, NWK=0000, Type=COORDINATOR
2017-07-25 17:15:48.755 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - 0: Starting mesh update
2017-07-25 17:15:48.757 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=05, startIndex=0]
2017-07-25 17:15:48.758 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=12, apiId=24 01, data=FE 0C 24 01 00 00 00 00 31 00 05 30 1F 02 00 00 30, checksum=30, error=false) 
2017-07-25 17:15:48.782 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:15:48.788 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 06 45 B1 00 00 00 00 00 00 F2)
2017-07-25 17:15:48.790 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=6, apiId=45 B1, data=FE 06 45 B1 00 00 00 00 00 00 F2, checksum=F2, error=false
2017-07-25 17:15:48.795 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableListCount=0, neighborTableList=[]]
2017-07-25 17:15:48.800 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF 00 00 00 31 80 00 00 00 00 00 00 00 00 06)
2017-07-25 17:15:48.801 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF 00 00 00 31 80 00 00 00 00 00 00 00 00 06, checksum=06, error=false
2017-07-25 17:15:48.803 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableListCount=0, neighborTableList=[]]
2017-07-25 17:15:48.804 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=06, nwkAddrOfInterest=0, requestType=1, startIndex=0]
2017-07-25 17:15:48.807 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=15, apiId=24 01, data=FE 0F 24 01 00 00 00 00 01 00 06 30 1F 05 00 00 00 01 00 06, checksum=06, error=false) 
2017-07-25 17:15:48.831 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:15:48.840 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 81 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 00 11)
2017-07-25 17:15:48.841 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 81, data=FE 0D 45 81 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 00 11, checksum=11, error=false
2017-07-25 17:15:48.843 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00124B000E0D7EFC, nwkAddrRemoteDev=0, numAssocDev=0, startIndex=null, nwkAddrAssocDevList=[]]
2017-07-25 17:15:48.846 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=07, startIndex=0]
2017-07-25 17:15:48.847 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 F6)
2017-07-25 17:15:48.848 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=12, apiId=24 01, data=FE 0C 24 01 00 00 00 00 32 00 07 30 1F 02 00 00 31, checksum=31, error=false) 
2017-07-25 17:15:48.849 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=21, apiId=45 FF, data=FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 F6, checksum=F6, error=false
2017-07-25 17:15:48.851 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00124B000E0D7EFC, nwkAddrRemoteDev=0, numAssocDev=0, startIndex=null, nwkAddrAssocDevList=[]]
2017-07-25 17:15:48.868 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:15:48.880 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 06 45 B2 00 00 00 00 00 00 F1)
2017-07-25 17:15:48.883 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=6, apiId=45 B2, data=FE 06 45 B2 00 00 00 00 00 00 F1, checksum=F1, error=false
2017-07-25 17:15:48.889 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=0, startIndex=0, routingTableListCount=0, routingTableList=[]]
2017-07-25 17:15:48.895 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF 00 00 00 32 80 00 00 00 00 00 00 00 00 05)
2017-07-25 17:15:48.895 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - 0: Ending mesh update
2017-07-25 17:15:48.918 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF 00 00 00 32 80 00 00 00 00 00 00 00 00 05, checksum=05, error=false
2017-07-25 17:15:48.922 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=0, startIndex=0, routingTableListCount=0, routingTableList=[]]
2017-07-25 17:16:08.481 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:6c91b58b
2017-07-25 17:16:08.494 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join for 60 seconds.
2017-07-25 17:16:08.500 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]
2017-07-25 17:16:08.502 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 FC FF 00 00 36 00 08 30 1F 03 00 3C 01 04, checksum=04, error=false) 
2017-07-25 17:16:08.526 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:16:48.752 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - 0: Starting mesh update
2017-07-25 17:16:48.753 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=09, startIndex=0]
2017-07-25 17:16:48.755 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=12, apiId=24 01, data=FE 0C 24 01 00 00 00 00 31 00 09 30 1F 02 00 00 3C, checksum=3C, error=false) 
2017-07-25 17:16:48.773 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:16:48.779 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 06 45 B1 00 00 00 00 00 00 F2)
2017-07-25 17:16:48.780 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=6, apiId=45 B1, data=FE 06 45 B1 00 00 00 00 00 00 F2, checksum=F2, error=false
2017-07-25 17:16:48.782 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableListCount=0, neighborTableList=[]]
2017-07-25 17:16:48.787 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF 00 00 00 31 80 00 00 00 00 00 00 00 00 06)
2017-07-25 17:16:48.789 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF 00 00 00 31 80 00 00 00 00 00 00 00 00 06, checksum=06, error=false
2017-07-25 17:16:48.790 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=0A, nwkAddrOfInterest=0, requestType=1, startIndex=0]
2017-07-25 17:16:48.790 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableListCount=0, neighborTableList=[]]
2017-07-25 17:16:48.791 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=15, apiId=24 01, data=FE 0F 24 01 00 00 00 00 01 00 0A 30 1F 05 00 00 00 01 00 0A, checksum=0A, error=false) 
2017-07-25 17:16:48.825 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:16:48.832 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 81 00 FC 7E 0D 0E 00 4B 12 00 00 00 9F 00 8E)
2017-07-25 17:16:48.834 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 81, data=FE 0D 45 81 00 FC 7E 0D 0E 00 4B 12 00 00 00 9F 00 8E, checksum=8E, error=false
2017-07-25 17:16:48.835 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00124B000E0D7EFC, nwkAddrRemoteDev=0, numAssocDev=0, startIndex=null, nwkAddrAssocDevList=[]]
2017-07-25 17:16:48.837 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=0B, startIndex=0]
2017-07-25 17:16:48.839 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=12, apiId=24 01, data=FE 0C 24 01 00 00 00 00 32 00 0B 30 1F 02 00 00 3D, checksum=3D, error=false) 
2017-07-25 17:16:48.839 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 F6)
2017-07-25 17:16:48.841 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=21, apiId=45 FF, data=FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 FC 7E 0D 0E 00 4B 12 00 00 00 00 F6, checksum=F6, error=false
2017-07-25 17:16:48.843 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00124B000E0D7EFC, nwkAddrRemoteDev=0, numAssocDev=0, startIndex=null, nwkAddrAssocDevList=[]]
2017-07-25 17:16:48.858 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:16:48.865 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 06 45 B2 00 00 00 00 00 00 F1)
2017-07-25 17:16:48.867 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=6, apiId=45 B2, data=FE 06 45 B2 00 00 00 00 00 00 F1, checksum=F1, error=false
2017-07-25 17:16:48.869 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=0, startIndex=0, routingTableListCount=0, routingTableList=[]]
2017-07-25 17:16:48.873 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - 0: Ending mesh update
2017-07-25 17:16:48.875 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF 00 00 00 32 80 00 00 00 00 00 00 00 00 05)
2017-07-25 17:16:48.876 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF 00 00 00 32 80 00 00 00 00 00 00 00 00 05, checksum=05, error=false

chris · July 26, 2017, 9:10am

Is the bulb you’re trying to use completely factory reset? If it’s been used with anything in the past (ie another Zigbee system, or the Hue bridge) then it must be reset first otherwise it will not be allowed to connect to a different network.

Looking at the log above, it seems that the basic communications is working with the dongle at least.

Jose90 · July 26, 2017, 3:17pm

Thanks for the reply. Yes I reset the hue bulbs by following the instructions provide by

https://community.smartthings.com/t/hue-bulb-factory-reset-solved-if-your-hue-bulb-is-on-a-zll-channel/84967
the following is a screen shot of the sniffer program.

chris · July 26, 2017, 4:58pm

Have you actually enabled discovery using the OH UI? Without this join will be disabled and I don’t see any join enable messages being sent (although the sniffer isn’t really decoding the frames fully) - maybe that’s just because the capture is too short, but join is only enabled for 30 seconds…

Jose90 · July 26, 2017, 5:36pm

I tried to use discovery in paper UI and Habmin. Here is the log:

2017-07-25 17:16:08.481 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:6c91b58b
2017-07-25 17:16:08.494 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join for 60 seconds.
2017-07-25 17:16:08.500 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]
2017-07-25 17:16:08.502 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 FC FF 00 00 36 00 08 30 1F 03 00 3C 01 04, checksum=04, error=false) 
2017-07-25 17:16:08.526 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:16:48.752 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - 0: Starting mesh update
2017-07-25 17:16:48.753 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=09, startIndex=0]
2017-07-25 17:16:48.755 [DEBUG] [31.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=12, apiId=24 01, data=FE 0C 24 01 00 00 00 00 31 00 09 30 1F 02 00 00 3C, checksum=3C, error=false) 
2017-07-25 17:16:48.773 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
2017-07-25 17:16:48.779 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 06 45 B1 00 00 00 00 00 00 F2)
2017-07-25 17:16:48.780 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=6, apiId=45 B1, data=FE 06 45 B1 00 00 00 00 00 00 F2, checksum=F2, error=false
2017-07-25 17:16:48.782 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableListCount=0, neighborTableList=[]]
2017-07-25 17:16:48.787 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF 00 00 00 31 80 00 00 00 00 00 00 00 00 06)
2017-07-25 17:16:48.789 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF 00 00 00 31 80 00 00 00 00 00 00 00 00 06, checksum=06, error=false

popsharma · January 6, 2018, 4:50pm

@chris Hi, how do you actually do this?
I have now got a ETRX357USB and got the right R309C firmware on it but am unable to discover any devices like the original poster.

chris · January 6, 2018, 4:55pm

In PaperUI, you can select the Inbox tab. You will then get a + button - if you select this you should get the list of bindings and hopefully ZigBee will be in this list. Click on ZigBee and it will enable joining on the network for a short time…

popsharma · January 6, 2018, 5:22pm

@chris many thanks for confirming that.
Sadly it’s not discovering my Hue bulb.

Here is some of the log from the last couple of minutes after I started discovery.
Any smoking guns in this?

        2018-01-06 17:18:52.025 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=66, startIndex=15]
    2018-01-06 17:18:52.026 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 41 43 4B 3A 36 41
    2018-01-06 17:18:52.029 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, sequence=102, payload=00 0F]
    2018-01-06 17:18:52.029 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisAckMessageEvent [messageId=106]
    2018-01-06 17:18:52.032 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 0F, messageId=null]
    2018-01-06 17:18:52.032 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisAckMessageEvent [messageId=106]
    2018-01-06 17:18:52.035 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=106]
    2018-01-06 17:18:52.036 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
    2018-01-06 17:18:52.043 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS TX: Data 41 54 2B 53 45 4E 44 55 43 41 53 54 42 3A 30 32 2C 30 30 30 30 2C 30 30 2C 30 30 2C 30 30 30 30 2C 30 30 33 32 0D 00 0F 0D 0A
    2018-01-06 17:18:52.244 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 53 45 51 3A 36 43
    2018-01-06 17:18:52.247 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 4F 4B
    2018-01-06 17:18:52.249 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis command complete: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 0F, messageId=108, status=SUCCESS]
    2018-01-06 17:18:52.261 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 52 58 3A 30 30 30 30 2C 30 30 30 30 2C 30 30 2C 30 30 2C 38 30 33 32 2C 35 30 3A 00 00 40 0F 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 2C 30 30 2C 46 46
    2018-01-06 17:18:52.266 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 0F 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, rssi=0, lqi=255]
    2018-01-06 17:18:52.271 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 0F 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, rssi=0, lqi=255]
    2018-01-06 17:18:52.275 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=0, payload=00 00 40 0F 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-01-06 17:18:52.279 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=15, routingTableListCount=15, 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-01-06 17:18:52.284 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 41 43 4B 3A 36 43
    2018-01-06 17:18:52.284 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=67, startIndex=30]
    2018-01-06 17:18:52.286 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisAckMessageEvent [messageId=108]
    2018-01-06 17:18:52.289 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisAckMessageEvent [messageId=108]
    2018-01-06 17:18:52.289 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, sequence=103, payload=00 1E]
    2018-01-06 17:18:52.290 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=108]
    2018-01-06 17:18:52.293 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 1E, messageId=null]
    2018-01-06 17:18:52.295 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
    2018-01-06 17:18:52.299 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS TX: Data 41 54 2B 53 45 4E 44 55 43 41 53 54 42 3A 30 32 2C 30 30 30 30 2C 30 30 2C 30 30 2C 30 30 30 30 2C 30 30 33 32 0D 00 1E 0D 0A
    2018-01-06 17:18:52.505 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 53 45 51 3A 36 45
    2018-01-06 17:18:52.510 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 4F 4B
    2018-01-06 17:18:52.513 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis command complete: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 1E, messageId=110, status=SUCCESS]
    2018-01-06 17:18:52.532 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 52 58 3A 30 30 30 30 2C 30 30 30 30 2C 30 30 2C 30 30 2C 38 30 33 32 2C 35 30 3A 00 00 40 1E 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 2C 30 30 2C 46 46
    2018-01-06 17:18:52.539 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 1E 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, rssi=0, lqi=255]
    2018-01-06 17:18:52.547 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 1E 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, rssi=0, lqi=255]
    2018-01-06 17:18:52.554 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=0, payload=00 00 40 1E 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-01-06 17:18:52.559 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=30, routingTableListCount=15, 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-01-06 17:18:52.569 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=68, startIndex=45]
    2018-01-06 17:18:52.572 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, sequence=104, payload=00 2D]
    2018-01-06 17:18:52.575 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 2D, messageId=null]
    2018-01-06 17:18:52.577 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
    2018-01-06 17:18:52.576 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 41 43 4B 3A 36 45
    2018-01-06 17:18:52.584 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS TX: Data 41 54 2B 53 45 4E 44 55 43 41 53 54 42 3A 30 32 2C 30 30 30 30 2C 30 30 2C 30 30 2C 30 30 30 30 2C 30 30 33 32 0D 00 2D 0D 0A
    2018-01-06 17:18:52.587 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisAckMessageEvent [messageId=110]
    2018-01-06 17:18:52.590 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisAckMessageEvent [messageId=110]
    2018-01-06 17:18:52.593 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=110]
    2018-01-06 17:18:52.783 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 53 45 51 3A 37 30
    2018-01-06 17:18:52.787 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 4F 4B
    2018-01-06 17:18:52.790 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis command complete: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 2D, messageId=112, status=SUCCESS]
    2018-01-06 17:18:52.800 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 52 58 3A 30 30 30 30 2C 30 30 30 30 2C 30 30 2C 30 30 2C 38 30 33 32 2C 35 30 3A 00 00 40 2D 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 2C 30 30 2C 46 46
    2018-01-06 17:18:52.805 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 2D 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, rssi=0, lqi=255]
    2018-01-06 17:18:52.809 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 2D 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, rssi=0, lqi=255]
    2018-01-06 17:18:52.814 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=0, payload=00 00 40 2D 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-01-06 17:18:52.819 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=45, routingTableListCount=15, 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-01-06 17:18:52.825 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 41 43 4B 3A 37 30
    2018-01-06 17:18:52.825 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=69, startIndex=60]
    2018-01-06 17:18:52.828 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, sequence=105, payload=00 3C]
    2018-01-06 17:18:52.828 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisAckMessageEvent [messageId=112]
    2018-01-06 17:18:52.830 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 3C, messageId=null]
    2018-01-06 17:18:52.833 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
    2018-01-06 17:18:52.833 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisAckMessageEvent [messageId=112]
    2018-01-06 17:18:52.837 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=112]
    2018-01-06 17:18:52.837 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS TX: Data 41 54 2B 53 45 4E 44 55 43 41 53 54 42 3A 30 32 2C 30 30 30 30 2C 30 30 2C 30 30 2C 30 30 30 30 2C 30 30 33 32 0D 00 3C 0D 0A
    2018-01-06 17:18:53.009 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 53 45 51 3A 37 32
    2018-01-06 17:18:53.012 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 4F 4B
    2018-01-06 17:18:53.015 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis command complete: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 3C, messageId=114, status=SUCCESS]
    2018-01-06 17:18:53.022 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 52 58 3A 30 30 30 30 2C 30 30 30 30 2C 30 30 2C 30 30 2C 38 30 33 32 2C 31 39 3A 00 00 40 3C 04 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 2C 30 30 2C 46 46
    2018-01-06 17:18:53.025 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 3C 04 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00, rssi=0, lqi=255]
    2018-01-06 17:18:53.028 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 3C 04 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00, rssi=0, lqi=255]
    2018-01-06 17:18:53.031 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=0, payload=00 00 40 3C 04 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
    2018-01-06 17:18:53.034 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=60, routingTableListCount=4, 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]]]
    2018-01-06 17:18:53.038 [DEBUG] [tems.zigbee.ZigBeeNetworkMeshMonitor] - 0: Ending mesh update
        2018-01-06 17:18:53.039 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TELEGESIS RX: Data 41 43 4B 3A 37 32
        2018-01-06 17:18:53.043 [DEBUG] [gesis.internal.TelegesisFrameHandler] - Telegesis event received: TelegesisAckMessageEvent [messageId=114]
        2018-01-06 17:18:53.045 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis RX: TelegesisAckMessageEvent [messageId=114]
        2018-01-06 17:18:53.047 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=114]

chris · January 6, 2018, 5:31pm

Not really - it looks like the join commands are being sent fine. Unfortunately there’s not a lot to say when it doesn’t work as nothing gets logged. The join is largely down to the coordinator at this stage - until the coordinator finds a device to join the binding simply doesn’t get any information at all…

What sort of device are you trying to join?

(please format logs using code fences, or the </> button - I’ve edited your post to try and correct this, but it’s still got extra spaces)

Benjy · January 6, 2018, 5:34pm

Was the hue bulb previously paired with a hub? If so, it will need factory resetting.

I’ve found that using the touchlink command from the hue bridge doesn’t actually reset the device to factory default. It seems to me that it re-pairs with the hue bridge after the touchlink command is done. I use the Hue dimmer switch to reset my bulbs and after this they’re available for discovery.

popsharma · January 6, 2018, 5:37pm

Sorry about that. I did try 3 times, but it just came out ‘normal’.

popsharma · January 6, 2018, 5:40pm

No, It is a brand new bulb. I don’t have a Hue hub. Before I updated the firmware, I could see responses from the bulb in the serial terminal (but not in openhab due to wrong firmware) does this count as being paired with the previous PAN?

chris · January 6, 2018, 5:46pm

Probably - the bulb will still think it’s linked to the old coordinator. Depending on how you loaded the firmware, the list of devices previously associated to the coordinator can be wiped.

I would suggest to reset the bulb.

popsharma · January 6, 2018, 6:06pm

Are there commands I can issue to the etrx3 that can reset the bulb, or do I need to obtain a hub or special remote control or something like raspBee? All which seem to defeat the point of using the etrx3 in the first place.

chris · January 6, 2018, 6:13pm

No - at least not directly. I’m actually about to test something to see if I can reset a Hue bulb, but I don’t give it a high probability of success.

I use a Hue controller like the one below which can reset via touchlink - I’m sure there are (probably!) other options out there. I think other Hue controllers also work.

Benjy · January 6, 2018, 6:36pm

To extend on that, I tried to find the the the circular hue remote, but had no success. If you can find the one above it’s usually cheap to buy. I use the standard dimmer remote instead:

popsharma · January 6, 2018, 7:20pm

@chris and @Benjy thanks for the advice. I will order whichever of the two I can find tonight.

popsharma · January 8, 2018, 8:23pm

OK. I managed to get a remote like the one you have @Benjy .
Please would you tell me what the magic button pressing sequence is to reset the bulb?

Benjy · January 8, 2018, 9:37pm

Turn the light off and on from the switch, then press and hold the top and bottom buttons while close to the light. The light will flash three times and then go dimly lit. Once that happens you can let go and your bulb is reset.

popsharma · January 8, 2018, 9:39pm

Thanks @Benjy I’ll get cracking.