Zigbee binding not working with Bitronvideo

Hi, I’m new here, and really am very much in the beginner bracket, taking my first dip into openhab. I posted this to the Zigbee thread a couple of days ago, but I think it’ll probably get lost in there. I’ve picked up a Bitronvideo ZigBee USB Radio Stick and attached it to a Linux device. It seems to be recognised by openhab just fine, but even with manual configuration I’m getting a statue of “OFFLINE - COMMUNICATION_ERROR”.

I have enabled logged as per the instructions, but to my newbie eyes, it doesn’t help very much. I’m not sure what to do next in troubleshooting this?

I think it seems to be going all ok until I get to a EMBER_NOT_JOINED status.

Log and Thing details:

Logs
22:08:02.780 [INFO ] [del.core.internal.ModelRepositoryImpl] - Refreshing model 'zigbee.things'
22:08:02.817 [DEBUG] [nding.zigbee.handler.ZigBeeSerialPort] - Serial port [/dev/zigbee] is initialized.
22:08:04.099 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspVersionResponse [protocolVersion=4, stackType=2, stackVersion=5800]
22:08:04.100 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspVersionResponse [protocolVersion=4, stackType=2, stackVersion=5800]
22:08:04.221 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
22:08:04.341 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=5]
22:08:04.461 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=8]
22:08:04.581 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
22:08:04.702 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
22:08:04.823 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=3000]
22:08:04.943 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=30]
22:08:05.064 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
22:08:05.185 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=1]
22:08:05.307 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=6]
22:08:05.427 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
22:08:05.549 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=32]
22:08:05.670 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=10]
22:08:05.791 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=15]
22:08:05.911 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=16]
22:08:06.043 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=75]
22:08:06.044 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_INDIRECT_TRANSMISSION_TIMEOUT = 3000
22:08:06.045 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_TX_POWER_MODE = 0
22:08:06.045 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_KEY_TABLE_SIZE = 6
22:08:06.045 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_APS_UNICAST_MESSAGE_COUNT = 10
22:08:06.045 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_PACKET_BUFFER_COUNT = 75
22:08:06.046 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_STACK_PROFILE = 0
22:08:06.046 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_MAX_END_DEVICE_CHILDREN = 32
22:08:06.046 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_MAX_HOPS = 30
22:08:06.046 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_BROADCAST_TABLE_SIZE = 15
22:08:06.046 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_APPLICATION_ZDO_FLAGS = 0
22:08:06.046 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_ADDRESS_TABLE_SIZE = 8
22:08:06.047 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SOURCE_ROUTE_TABLE_SIZE = 0
22:08:06.047 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SUPPORTED_NETWORKS = 1
22:08:06.047 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_NEIGHBOR_TABLE_SIZE = 16
22:08:06.047 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE = 0
22:08:06.048 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SECURITY_LEVEL = 5
22:08:06.157 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_ALLOW_PRECONFIGURED_KEY_JOINS]
22:08:06.282 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_DISALLOW_BINDING_MODIFICATION]
22:08:06.400 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_MESSAGE_TAG_ONLY_IN_CALLBACK]
22:08:06.526 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_DENY_TC_KEY_REQUESTS]
22:08:06.526 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_BINDING_MODIFICATION_POLICY = EZSP_DISALLOW_BINDING_MODIFICATION
22:08:06.527 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_MESSAGE_CONTENTS_IN_CALLBACK_POLICY = EZSP_MESSAGE_TAG_ONLY_IN_CALLBACK
22:08:06.527 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_TC_KEY_REQUEST_POLICY = EZSP_DENY_TC_KEY_REQUESTS
22:08:06.527 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_TRUST_CENTER_POLICY = EZSP_ALLOW_PRECONFIGURED_KEY_JOINS
22:08:06.528 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_SOURCE_ROUTE_TABLE_SIZE, value=16]
22:08:06.647 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:06.647 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_SECURITY_LEVEL, value=5]
22:08:06.771 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:06.772 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_ADDRESS_TABLE_SIZE, value=8]
22:08:06.894 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:06.895 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE, value=2]
22:08:07.013 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.013 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_STACK_PROFILE, value=2]
22:08:07.132 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.133 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_INDIRECT_TRANSMISSION_TIMEOUT, value=7680]
22:08:07.253 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.253 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_MAX_HOPS, value=30]
22:08:07.374 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.374 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_TX_POWER_MODE, value=1]
22:08:07.496 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.496 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_SUPPORTED_NETWORKS, value=1]
22:08:07.617 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.617 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_KEY_TABLE_SIZE, value=4]
22:08:07.737 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.738 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_APPLICATION_ZDO_FLAGS, value=1]
22:08:07.858 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.858 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_MAX_END_DEVICE_CHILDREN, value=16]
22:08:07.979 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:07.979 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_APS_UNICAST_MESSAGE_COUNT, value=10]
22:08:08.099 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:08.100 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_BROADCAST_TABLE_SIZE, value=15]
22:08:08.222 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_ERROR_INVALID_VALUE]
22:08:08.222 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_NEIGHBOR_TABLE_SIZE, value=16]
22:08:08.341 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:08.341 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_PACKET_BUFFER_COUNT, value=255]
22:08:08.462 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
22:08:08.582 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=16]
22:08:08.703 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=5]
22:08:08.823 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=8]
22:08:08.944 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=2]
22:08:09.065 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=2]
22:08:09.186 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=7680]
22:08:09.306 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=30]
22:08:09.427 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=1]
22:08:09.547 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=1]
22:08:09.677 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=4]
22:08:09.805 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=1]
22:08:09.923 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=16]
22:08:10.044 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=10]
22:08:10.164 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=15]
22:08:10.285 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=16]
22:08:10.406 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=255]
22:08:10.406 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_INDIRECT_TRANSMISSION_TIMEOUT = 7680
22:08:10.406 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_TX_POWER_MODE = 1
22:08:10.406 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_KEY_TABLE_SIZE = 4
22:08:10.406 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_APS_UNICAST_MESSAGE_COUNT = 10
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_PACKET_BUFFER_COUNT = 255
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_STACK_PROFILE = 2
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_MAX_END_DEVICE_CHILDREN = 16
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_MAX_HOPS = 30
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_BROADCAST_TABLE_SIZE = 15
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_APPLICATION_ZDO_FLAGS = 1
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_ADDRESS_TABLE_SIZE = 8
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SOURCE_ROUTE_TABLE_SIZE = 16
22:08:10.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SUPPORTED_NETWORKS = 1
22:08:10.408 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_NEIGHBOR_TABLE_SIZE = 16
22:08:10.408 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE = 2
22:08:10.408 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SECURITY_LEVEL = 5
22:08:10.526 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetPolicyResponse [status=EZSP_SUCCESS]
22:08:10.647 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetPolicyResponse [status=EZSP_SUCCESS]
22:08:10.768 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetPolicyResponse [status=EZSP_SUCCESS]
22:08:10.888 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspSetPolicyResponse [status=EZSP_SUCCESS]
22:08:11.009 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_ALLOW_PRECONFIGURED_KEY_JOINS]
22:08:11.130 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_CHECK_BINDING_MODIFICATIONS_ARE_VALID_ENDPOINT_CLUSTERS]
22:08:11.250 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_MESSAGE_TAG_ONLY_IN_CALLBACK]
22:08:11.371 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_GENERATE_NEW_TC_LINK_KEY]
22:08:11.371 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_BINDING_MODIFICATION_POLICY = EZSP_CHECK_BINDING_MODIFICATIONS_ARE_VALID_ENDPOINT_CLUSTERS
22:08:11.371 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_MESSAGE_CONTENTS_IN_CALLBACK_POLICY = EZSP_MESSAGE_TAG_ONLY_IN_CALLBACK
22:08:11.371 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_TC_KEY_REQUEST_POLICY = EZSP_GENERATE_NEW_TC_LINK_KEY
22:08:11.372 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_TRUST_CENTER_POLICY = EZSP_ALLOW_PRECONFIGURED_KEY_JOINS
22:08:11.492 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember local IEEE Address is 000D6F000C86D853
22:08:11.733 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspAddEndpointResponse [status=EZSP_SUCCESS]
22:08:11.853 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspNetworkInitResponse [status=EMBER_NOT_JOINED]
22:08:12.098 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=FFFF000000000000]]
22:08:12.099 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - Error during retrieval of security parameters: EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=FFFF000000000000]]
22:08:12.099 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize done: Initialised false
22:08:12.099 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING
22:08:12.100 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
22:08:12.101 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - ZigBee Initialise: Previous device configuration was: channel=CHANNEL_00, PanID=65535, EPanId=0000000000000000
22:08:12.101 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle startup.
22:08:12.216 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspNetworkStateResponse [status=EMBER_NO_NETWORK]
22:08:12.217 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP networkStateResponse EMBER_NO_NETWORK
22:08:12.458 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspNetworkStateResponse [status=EMBER_NO_NETWORK]
22:08:12.459 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP networkStateResponse EMBER_NO_NETWORK
22:08:12.580 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=FFFF000000000000]]
22:08:12.581 [DEBUG] [tsystems.zigbee.dongle.ember.EmberNcp] - Error during retrieval of security parameters: EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=FFFF000000000000]]
22:08:12.582 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Current Security State = null
22:08:12.701 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Current Parent Child Information = EzspGetParentChildParametersResponse [childCount=0, parentEui64=0000000000000000, parentNodeId=0]
22:08:12.942 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE
22:08:12.943 [DEBUG] [gbee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE
22:08:12.944 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:stick' changed from UNKNOWN to OFFLINE: Failed to startup ZigBee transport layer
22:08:12.947 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:stick' changed from OFFLINE: Failed to startup ZigBee transport layer to OFFLINE (COMMUNICATION_ERROR)
Thing
Thing zigbee:coordinator_ember:stick "Zigbee USB Stick" [zigbee_port="/dev/zigbee", zigbee_baud=57600, zigbee_flowcontrol=2, zigbee_childtimeout=864000, zigbee_concentrator=1, zigbee_meshupdateperiod=86400, zigbee_panid=16412, zigbee_extendedpanid="9D45E897E2B8E95A", zigbee_networkkey="54 90 6A 05 E1 C3 BF CF DB 31 95 C5 CB E3 D5 66", zigbee_powermode=1, zigbee_txpower=8]

Try reinitialising the stick by setting initialize to true in PaperUI.

I have tried removing the file configuration, and re-adding the device through the discovery. When I use the reset toggle in the configuration I get a 500 Internal Server Error flash up briefly

Logs have a NullPointerException:

StackTrace
20:47:51.533 [ERROR] [est.core.internal.thing.ThingResource] - Exception during HTTP PUT request for update config at 'things/zigbee:coordinator_ember:01370DEE/config'
java.lang.NullPointerException: null
        at com.zsmartsystems.zigbee.app.discovery.ZigBeeDiscoveryExtension.extensionShutdown(ZigBeeDiscoveryExtension.java:96) ~[?:?]
        at com.zsmartsystems.zigbee.ZigBeeNetworkManager.shutdown(ZigBeeNetworkManager.java:529) ~[?:?]
        at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.dispose(ZigBeeCoordinatorHandler.java:303) ~[?:?]
        at org.openhab.binding.zigbee.ember.handler.EmberHandler.dispose(EmberHandler.java:128) ~[?:?]
        at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.handleConfigurationUpdate(ZigBeeCoordinatorHandler.java:554) ~[?:?]
        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.updateConfiguration(ThingRegistryImpl.java:91) ~[?:?]
        at org.eclipse.smarthome.io.rest.core.internal.thing.ThingResource.updateConfiguration(ThingResource.java:438) [120:org.eclipse.smarthome.io.rest.core:0.10.0.oh240]
        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
        at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [171:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [172:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [169:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
        at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.4.11.v20180605]
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [85:org.eclipse.jetty.servlet:9.4.11.v20180605]
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [186:org.ops4j.pax.web.pax-web-jetty:7.2.3]
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.Server.handle(Server.java:531) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [84:org.eclipse.jetty.server:9.4.11.v20180605]
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) [75:org.eclipse.jetty.io:9.4.11.v20180605]
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) [75:org.eclipse.jetty.io:9.4.11.v20180605]
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [75:org.eclipse.jetty.io:9.4.11.v20180605]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [87:org.eclipse.jetty.util:9.4.11.v20180605]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [87:org.eclipse.jetty.util:9.4.11.v20180605]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [87:org.eclipse.jetty.util:9.4.11.v20180605]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [87:org.eclipse.jetty.util:9.4.11.v20180605]
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [87:org.eclipse.jetty.util:9.4.11.v20180605]
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762) [87:org.eclipse.jetty.util:9.4.11.v20180605]
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680) [87:org.eclipse.jetty.util:9.4.11.v20180605]
        at java.lang.Thread.run(Thread.java:834) [?:?]

You can probably ignore this - it’s just a shutdown issue, not a startup.

Figured it. I had some misconfigured items completely unrelated, once I removed those everything sprung into life and it’s all working ok now.

And now it’s not working again this morning.

It also seems to fall apart miserably when I’m using a udev symlink for the USB port. I’ve mapped /dev/ttyUSB0 through to /dev/zigbee as the USB order isn’t gauranteed - but the binding falls over with the above null error.

Please provide a full set of debug logs so I can see what is happening as I don’t really see any “null error” in the short log you’ve provided. Yes, there are some nulls logged, but that’s fine as the information is not known at that time.

Right, I have managed to get it working again. I basically had to delete everything and restart it a few times. I have now got it configured via a udev alias using a file instead of a UI, as the UI approach didn’t seem to want to work (it was constantly trying to use ttyUSB0).

But now I’m back round to the problem I had this morning. I have successfully paired up a couple Aqare temperature sensors which were working fine. But now they’re showing as offline, whilst the stick is showing as online.

Periodic updates don’t seem to be showing a lot

Log
13:40:06.676 [DEBUG] [pp.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update
13:40:06.683 [DEBUG] [pp.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 000D6F000C86D853
13:40:06.684 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: Update mesh
13:40:06.685 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: scheduled [ROUTES, NEIGHBORS]
13:40:07.587 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: running
13:40:07.588 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=1D, startIndex=0]
13:40:07.589 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=29, payload=00 00]
13:40:07.590 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=29], messageTag=29, messageContents=00 00]
13:40:07.731 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=179]
13:40:07.731 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=179]
13:40:07.732 [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=179], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
13:40:07.733 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, apsSecurity=false, apsCounter=179, payload=00 00]
13:40:07.734 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=0]
13:40:07.739 [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=180], 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]
13:40:07.740 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=180, 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]
13:40:07.743 [DEBUG] [rtsystems.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]]]
13:40:07.745 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=179], messageTag=29, status=EMBER_SUCCESS, messageContents=]
13:40:07.746 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=179], messageTag=29, status=EMBER_SUCCESS, messageContents=]
13:40:07.747 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=1D, startIndex=0]
13:40:07.750 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: 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]]]]
13:40:07.753 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=1E, startIndex=15]
13:40:07.754 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=30, payload=00 0F]
13:40:07.755 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=30], messageTag=30, messageContents=00 0F]
13:40:07.885 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=181]
13:40:07.885 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=181]
13:40:07.887 [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=181], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 0F]
13:40:07.888 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, apsSecurity=false, apsCounter=181, payload=00 0F]
13:40:07.889 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=15]
13:40:07.891 [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=182], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 0F 01 00 00 03 00 00]
13:40:07.895 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=182, payload=00 00 10 0F 01 00 00 03 00 00]
13:40:07.896 [DEBUG] [rtsystems.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]]]
13:40:07.897 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=181], messageTag=30, status=EMBER_SUCCESS, messageContents=]
13:40:07.898 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=181], messageTag=30, status=EMBER_SUCCESS, messageContents=]
13:40:07.900 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=1E, startIndex=15]
13:40:07.901 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: 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]]]]
13:40:07.902 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: ManagementLqiRequest complete [1 routes]
13:40:07.904 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - 000D6F000C86D853: Routing table NEW: [RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
13:40:07.905 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - 000D6F000C86D853: Routing table OLD: [RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
13:40:07.905 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - 000D6F000C86D853: Routing table unchanged
13:40:07.906 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: request ROUTES successful. Advanced to NEIGHBORS.
13:40:07.907 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: running
13:40:07.909 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1F, startIndex=0]
13:40:07.910 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=31, payload=00 00]
13:40:07.911 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=31], messageTag=31, messageContents=00 00]
13:40:08.037 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=183]
13:40:08.038 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=183]
13:40:08.039 [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=183], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
13:40:08.040 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=null, radius=0, apsSecurity=false, apsCounter=183, payload=00 00]
13:40:08.041 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=NULL, startIndex=0]
13:40:08.043 [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=184], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 00 00 00]
13:40:08.044 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=184, payload=00 00 00 00 00]
13:40:08.045 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]
13:40:08.047 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1F, startIndex=0]
13:40:08.048 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]]
13:40:08.049 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: ManagementLqiRequest complete [0 neighbors]
13:40:08.048 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=183], messageTag=31, status=EMBER_SUCCESS, messageContents=]
13:40:08.050 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - 000D6F000C86D853: Neighbor table unchanged
13:40:08.051 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=183], messageTag=31, status=EMBER_SUCCESS, messageContents=]
13:40:08.052 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: request NEIGHBORS successful. Advanced to null.
13:40:08.053 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: running
13:40:08.054 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 000D6F000C86D853: Node SVC Discovery: complete
13:40:08.055 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 000D6F000C86D853: Node 0 update
13:40:08.059 [DEBUG] [rnal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
13:40:08.062 [DEBUG] [rnal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
13:40:24.342 [INFO ] [smarthome.event.ItemStateChangedEvent] - ZigbeeUSBStick_DataFramesReceived changed from 183 to 195
13:40:24.347 [INFO ] [smarthome.event.ItemStateChangedEvent] - ZigbeeUSBStick_DataFramesSent changed from 103 to 106
13:40:24.347 [INFO ] [smarthome.event.ItemStateChangedEvent] - ZigbeeUSBStick_ACKFramesSent changed from 183 to 195

So think my next step is to try and reset one and watch the logs for it falling off?

There is a ZigBee log viewer to help interpret the logs for you.

https://www.cd-jackson.com/index.php/openhab/zigbee-log-viewer

1 Like

What do you mean by “periodic updates”? What devices do you have, what is not updating, what should be updating, how are things configured, what version of the binding are you using?

I’d really need to see a log to understand what’s happening, but it would also be good to describe what you expect, and what is happening.

I have two Aqara temperature sensors (figured start small), which were working last night, but then marked as offline. I stripped everything back and tried again this morning and they were working again - for a while. They are now showing as offline, although they’ll light up if you jab them (suggests battery is working).

I’ve just tried removing one, resetting it and then re-adding it. Whilst it was initially discovered, it never completed discovery.

I’ve uploaded a large section of my log today to: http://tmp.aligrant.com/openhab.log

I’m using the Zigbee binding from the addons page of Paper UI, listed as version 2.4.0

What I’m expecting is the temperature sensors to show as online and give temperature updates in openhab for more than an hour or so.

My first suggestion is to use a newer binding. 2.4 is now 1 year old (well, over 11 months anyway!).

Xiaomi devices a notoriously difficult to use, so I would also suggest to search the forum. Many people have reported problems with them if they use routers in the network which may indicate some incompatibility with ZigBee.

1 Like

I’ve removed openHAB and installed 2.5 M5 from the repository. I seem to be in an even worse position now, as whilst the temperature sensor is recognised, it never completes discovery.

Looking at my log http://tmp.aligrant.com/openhab.log (updated), it seems to be getting perpetually stuck discovering POWER_DESCRIPTOR:

2019-11-25 09:48:22.850 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0004445250: Node SVC Discovery: PowerDescriptorResponse returned null
2019-11-25 09:48:22.851 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0004445250: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 11, wait 17552ms before retry.

I’m not using any routers etc in my network, I’m just trying to get the basics to work, before getting complicated and adding a light bulb.

Are you waking up the device during this discovery phase? Either the device isn’t awake, or it just doesn’t respond and I know the Aqara devices can be problematic as they tend to sleep very quickly.

Unfortunately I can’t download your log at the moment so will have to check this another time.

I’ve tried jabbing the ping button on it fairly furiously during the discovery phase as I read that on another post. Doesn’t seem to have any impact.

I’ve tried searching for alternative temperature sensors, but they largely look like clones of the Aqara one, which I would assume probably pack the same issues.

I’ve had the sensors working for 24 hours now. What I did was update to openhab 2.5 M5 test version. Once again, when discovered through openhab, the sensors don’t work: they’ll be discovered but never fully configure.

When I use the things file (first post) things fair better and I can attach the sensors. I’ll keep an eye on it for a while.