Setup HUSBZB-1 (EMBER EM35x Coordinator) Help Please

5iver · September 21, 2017, 2:42am

That’s odd. Did you happen to unplug the stick and then plug it back in again? If so, it could have come up on different ports. A system restart should put them back, or you could look into udev rules to make them static. If not, I don’t know what could cause this, but you could do a bundle:list in Karaf console and you’ll see something like this:

openhab> bundle:list
START LEVEL 100 , List Threshold: 50
 ID │ State    │ Lvl │ Version                │ Name
────┼──────────┼─────┼────────────────────────┼────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
 15 │ Active   │  80 │ 2.1.0.201709182108     │ ZWave Binding
 16 │ Active   │  80 │ 2.2.0.201709152241     │ ZigBee Binding
 17 │ Active   │  80 │ 5.3.1.201602281253     │ OSGi JAX-RS Connector
 18 │ Active   │  80 │ 2.4.5                  │ Jackson-annotations
 19 │ Active   │  80 │ 2.4.5                  │ Jackson-core
 20 │ Active   │  80 │ 2.4.5                  │ jackson-databind
 21 │ Active   │  80 │ 2.4.5                  │ Jackson-dataformat-XML

If the binding state is Resolved, then it is not started. Do a bundle:start X, where X is the ID listed from the bundle:list results. Here I have zwave on ID 15 and zigbee on ID 16. Did you see anything in the logs?

wormuths · September 21, 2017, 10:54pm

Bindings show as active. Z-Wave on /dev/ttyUSB0 shows “OFFLINE - COMMUNICATION_ERROR zwave.thingstate.serial_notfound” and ZigBee controller shows “OFFLINE - COMMUNICATION_ERROR Serial Error: Port/dev/ttyUSB1 does not exist”.

Looks like this is now a port issue…

dmesg | grep tty
[    0.000000] console [tty0] enabled
[   23.773896] usb 8-1.1: cp210x converter now attached to ttyUSB0
[   23.781596] usb 8-1.1: cp210x converter now attached to ttyUSB1
[   24.046497] cp210x ttyUSB1: failed set req 0x1e size 4 status: -32
[   24.046503] cp210x ttyUSB1: failed to set baud rate to 300
[  184.798996] cp210x ttyUSB1: failed get req 0x1d size 4 status: -110
[  184.799006] cp210x ttyUSB1: failed get req 0x4 size 2 status: -19
[  184.799019] cp210x ttyUSB1: failed set request 0x3 status: -19
[  184.799035] cp210x ttyUSB1: failed set request 0x3 status: -19
[  184.799047] cp210x ttyUSB1: failed set request 0x3 status: -19
[  184.799052] cp210x ttyUSB1: failed get req 0x14 size 16 status: -19
[  184.799059] cp210x ttyUSB1: failed set req 0x1e size 4 status: -19
[  184.799063] cp210x ttyUSB1: failed to set baud rate to 300
[  184.799255] cp210x ttyUSB0: failed set request 0x0 status: -19
[  184.799260] cp210x ttyUSB0: cp210x_open - Unable to enable UART
[  184.803084] cp210x ttyUSB1: failed set request 0x0 status: -19
[  184.803091] cp210x ttyUSB1: cp210x_open - Unable to enable UART
[  184.803158] cp210x ttyUSB0: failed set request 0x0 status: -19
[  184.803162] cp210x ttyUSB0: cp210x_open - Unable to enable UART
[  199.110051] cp210x ttyUSB0: cp210x converter now disconnected from ttyUSB0
[  199.110401] cp210x ttyUSB1: cp210x converter now disconnected from ttyUSB1

ttyUSB0 or ttyUSB1 dont show in ls /dev/tty*. Tried unplugging and reinserting the stick.

5iver · September 22, 2017, 4:15am

Is there any power management enabled on your USB ports? Also, are you unplugging the stick while OH is running (best not to)? What happens after rebooting the system?

wormuths · September 23, 2017, 12:37am

No. I left it running for a day when they were online and they stayed that way. I didn’t do anything except reboot and the port situation occurred. I have a request out in the Mint forum looking for answers to that issue.

wormuths · September 23, 2017, 1:39pm

Another restart and up they came. Strange.

I’m eliminating my frustration by playing with some other things in here for a while. Got the Hue lights installed, got a stereo that’s supported, plex, etc… I’ll play with those things for a while instead of frustrating myself to the point of quitting over zigbee.

I’ll keep this thread posted if they go offline again.

jdavisonc · December 4, 2017, 1:30am

Hi All, I recently bought a HUBBZB-1 dongle, zwave binding works perfectly but not the zigbee.
The thing keep saying zigbee.status.offline_startupfail

Someone had a similar problem?

/dev/ttyUSB1, Baud is on 57600
here part of the final log on debug,

2017-12-03 22:22:55.150 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=0, ackNum=0, reTx=false, data=31 00 02 01 04 01 00 00 00 01 01 00 00 00 00]
2017-12-03 22:22:55.262 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=1, reTx=false, data=31 80 02 00]
2017-12-03 22:22:55.264 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspAddEndpointResponse [status=EZSP_SUCCESS]
2017-12-03 22:22:55.264 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1]
2017-12-03 22:22:55.264 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspAddEndpointResponse [status=EZSP_SUCCESS]
2017-12-03 22:22:55.265 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP queue: 1
2017-12-03 22:22:55.266 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP: EzspGetNetworkParametersRequest []
2017-12-03 22:22:55.267 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=1, ackNum=1, reTx=false, data=32 00 28]
2017-12-03 22:22:55.385 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=2, reTx=false, data=32 80 28 93 00 00 00 00 00 00 00 00 00 FF FF FF 00 00 FF FF 00 00 00 00 00]
2017-12-03 22:22:55.386 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspGetNetworkParametersResponse [status=EMBER_NOT_JOINED, nodeType=EMBER_UNKNOWN_DEVICE, parameters=EmberNetworkParameters [extendedPanId={00 00 00 00 00 00 00 00}, panId=65535, radioTxPower=255, radioChannel=0, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=65535, nwkUpdateId=0, channels=00000000]]
2017-12-03 22:22:55.387 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2]
2017-12-03 22:22:55.391 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetNetworkParametersResponse [status=EMBER_NOT_JOINED, nodeType=EMBER_UNKNOWN_DEVICE, parameters=EmberNetworkParameters [extendedPanId={00 00 00 00 00 00 00 00}, panId=65535, radioTxPower=255, radioChannel=0, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=65535, nwkUpdateId=0, channels=00000000]]
2017-12-03 22:22:55.393 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP queue: 1
2017-12-03 22:22:55.394 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP: EzspGetCurrentSecurityStateRequest []
2017-12-03 22:22:55.394 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=2, ackNum=2, reTx=false, data=33 00 69]
2017-12-03 22:22:55.506 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=3, reTx=false, data=33 80 69 93 00 05 11 41 03 00 00 00 03 00]
2017-12-03 22:22:55.513 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=0003000000034111]]
2017-12-03 22:22:55.513 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3]
2017-12-03 22:22:55.514 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=0003000000034111]]
2017-12-03 22:22:55.515 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Error during retrieval of security parameters: EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=0003000000034111]]
2017-12-03 22:22:55.516 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize done: Initialised true
2017-12-03 22:22:55.523 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - null: Node 0 is added to the network

FunMiles · June 24, 2018, 4:43pm

I have this device and am trying to use it for the first time.
Paper UI is showing online, yet the log’s last few things about zigbee say:

/var/log/openhab2/events.log:9797:2018-06-24 10:30:35.781 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from UNINITIALIZED to INITIALIZING
/var/log/openhab2/events.log:9798:2018-06-24 10:30:35.825 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from INITIALIZING to UNKNOWN
/var/log/openhab2/events.log:9804:2018-06-24 10:30:38.522 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from UNKNOWN to OFFLINE: Failed to startup ZigBee transport layer
/var/log/openhab2/events.log:9942:2018-06-24 10:30:49.518 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from OFFLINE: Failed to startup ZigBee transport layer to ONLINE
/var/log/openhab2/events.log:9943:2018-06-24 10:30:49.559 [nt.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:coordinator_ember:0844a8aa changed to UNKNOWN.
/var/log/openhab2/events.log:9944:2018-06-24 10:30:49.956 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.

Last one to me looks like it failed to start up. How come it says online? Is it really online or does it have a problem?

Another zipbee-beginner question: How do you pair devices with this? With the Z-Stick 5 for ZWave, there’s a button for that. But here, I don’t see anything in the paperUI to put it into inclusion mode.

chris · June 24, 2018, 4:58pm

The last line is fine - it just says the thing was updated - probably the properties were updated (just guessing as the events log doesn’t really provide much information).

Before that there is an OFFLINE, then 10 seconds later it shows ONLINE. Maybe it’s started ok? I’d suggest to put the binding into debug and checking the log to see what’s happening - this doesn’t really provide a lot to go on.

FunMiles · June 24, 2018, 5:33pm

I put

log:set debug org.openhab.binding.zigbee
log:set debug com.zsmartsystems.zigbee

After that, I got a lot of output:

/var/log/openhab2/events.log:9491:2018-06-24 10:03:28.279 [thome.event.ExtensionEvent] - Extension 'binding-zigbee' has been installed.
/var/log/openhab2/events.log:9493:2018-06-24 10:06:35.563 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from UNINITIALIZED to INITIALIZING
/var/log/openhab2/events.log:9494:2018-06-24 10:06:35.628 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.
/var/log/openhab2/events.log:9495:2018-06-24 10:06:35.668 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.
/var/log/openhab2/events.log:9496:2018-06-24 10:06:35.697 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.
/var/log/openhab2/events.log:9497:2018-06-24 10:06:35.756 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from INITIALIZING to UNKNOWN
/var/log/openhab2/events.log:9498:2018-06-24 10:06:35.769 [nt.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:coordinator_ember:0844a8aa changed to UNKNOWN.
/var/log/openhab2/events.log:9499:2018-06-24 10:07:49.725 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.
/var/log/openhab2/events.log:9500:2018-06-24 10:08:33.506 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.
/var/log/openhab2/events.log:9501:2018-06-24 10:10:16.756 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.
/var/log/openhab2/events.log:9502:2018-06-24 10:10:19.039 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from UNKNOWN to OFFLINE: Failed to startup ZigBee transport layer
/var/log/openhab2/events.log:9503:2018-06-24 10:10:29.394 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from OFFLINE: Failed to startup ZigBee transport layer to ONLINE
/var/log/openhab2/events.log:9504:2018-06-24 10:10:29.790 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.
/var/log/openhab2/events.log:9511:2018-06-24 10:22:52.618 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from ONLINE to UNINITIALIZED
/var/log/openhab2/events.log:9512:2018-06-24 10:22:52.719 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
/var/log/openhab2/events.log:9797:2018-06-24 10:30:35.781 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from UNINITIALIZED to INITIALIZING
/var/log/openhab2/events.log:9798:2018-06-24 10:30:35.825 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from INITIALIZING to UNKNOWN
/var/log/openhab2/events.log:9804:2018-06-24 10:30:38.522 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from UNKNOWN to OFFLINE: Failed to startup ZigBee transport layer
/var/log/openhab2/events.log:9942:2018-06-24 10:30:49.518 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0844a8aa' changed from OFFLINE: Failed to startup ZigBee transport layer to ONLINE
/var/log/openhab2/events.log:9943:2018-06-24 10:30:49.559 [nt.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:coordinator_ember:0844a8aa changed to UNKNOWN.
/var/log/openhab2/events.log:9944:2018-06-24 10:30:49.956 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_ember:0844a8aa' has been updated.
/var/log/openhab2/openhab.log:4550:2018-06-24 11:25:49.973 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: Node SVC Discovery scheduled [ROUTES, NEIGHBORS]
/var/log/openhab2/openhab.log:4551:2018-06-24 11:25:50.262 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: Node SVC Discovery running
/var/log/openhab2/openhab.log:4552:2018-06-24 11:25:50.272 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=23, startIndex=0]
/var/log/openhab2/openhab.log:4553:2018-06-24 11:25:50.277 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, sequence=35, payload=00 00]
/var/log/openhab2/openhab.log:4554:2018-06-24 11:25:50.280 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=35], messageTag=35, messageContents=00 00]
/var/log/openhab2/openhab.log:4561:2018-06-24 11:25:50.448 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=249]
/var/log/openhab2/openhab.log:4562:2018-06-24 11:25:50.450 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=249]
/var/log/openhab2/openhab.log:4566:2018-06-24 11:25:50.467 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=249], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
/var/log/openhab2/openhab.log:4567:2018-06-24 11:25:50.469 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, sequence=35, payload=00 00]
/var/log/openhab2/openhab.log:4568:2018-06-24 11:25:50.471 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=0]
/var/log/openhab2/openhab.log:4572:2018-06-24 11:25:50.479 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=250], 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]
/var/log/openhab2/openhab.log:4573:2018-06-24 11:25:50.484 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=35, 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]
/var/log/openhab2/openhab.log:4574:2018-06-24 11:25:50.486 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=0, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
/var/log/openhab2/openhab.log:4575:2018-06-24 11:25:50.488 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: 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]]]]
/var/log/openhab2/openhab.log:4576:2018-06-24 11:25:50.489 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=24, startIndex=15]
/var/log/openhab2/openhab.log:4577:2018-06-24 11:25:50.490 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, sequence=36, payload=00 0F]
/var/log/openhab2/openhab.log:4578:2018-06-24 11:25:50.492 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=36], messageTag=36, messageContents=00 0F]
/var/log/openhab2/openhab.log:4585:2018-06-24 11:25:50.503 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=249], messageTag=35, status=EMBER_SUCCESS, messageContents=]
/var/log/openhab2/openhab.log:4586:2018-06-24 11:25:50.505 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=249], messageTag=35, status=EMBER_SUCCESS, messageContents=]
/var/log/openhab2/openhab.log:4591:2018-06-24 11:25:50.632 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=251]
/var/log/openhab2/openhab.log:4592:2018-06-24 11:25:50.634 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=251]
/var/log/openhab2/openhab.log:4596:2018-06-24 11:25:50.641 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=251], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 0F]
/var/log/openhab2/openhab.log:4597:2018-06-24 11:25:50.643 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, sequence=36, payload=00 0F]
/var/log/openhab2/openhab.log:4598:2018-06-24 11:25:50.644 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=15]
/var/log/openhab2/openhab.log:4602:2018-06-24 11:25:50.652 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=252], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 0F 01 00 00 03 00 00]
/var/log/openhab2/openhab.log:4603:2018-06-24 11:25:50.654 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=36, payload=00 00 10 0F 01 00 00 03 00 00]
/var/log/openhab2/openhab.log:4604:2018-06-24 11:25:50.655 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
/var/log/openhab2/openhab.log:4605:2018-06-24 11:25:50.657 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: 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]]]]
/var/log/openhab2/openhab.log:4606:2018-06-24 11:25:50.658 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000B131242: Routing table NEW: [RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
/var/log/openhab2/openhab.log:4607:2018-06-24 11:25:50.659 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000B131242: Routing table OLD: [RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
/var/log/openhab2/openhab.log:4608:2018-06-24 11:25:50.661 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000B131242: Routing table unchanged
/var/log/openhab2/openhab.log:4609:2018-06-24 11:25:50.662 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: Node SVC Discovery request ROUTES successful. Advanced to NEIGHBORS.
/var/log/openhab2/openhab.log:4611:2018-06-24 11:25:50.664 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: Node SVC Discovery running
/var/log/openhab2/openhab.log:4614:2018-06-24 11:25:50.666 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=251], messageTag=36, status=EMBER_SUCCESS, messageContents=]
/var/log/openhab2/openhab.log:4615:2018-06-24 11:25:50.667 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=251], messageTag=36, status=EMBER_SUCCESS, messageContents=]
/var/log/openhab2/openhab.log:4616:2018-06-24 11:25:50.666 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=25, startIndex=0]
/var/log/openhab2/openhab.log:4617:2018-06-24 11:25:50.669 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, sequence=37, payload=00 00]
/var/log/openhab2/openhab.log:4619:2018-06-24 11:25:50.672 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=37], messageTag=37, messageContents=00 00]
/var/log/openhab2/openhab.log:4626:2018-06-24 11:25:50.812 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=253]
/var/log/openhab2/openhab.log:4627:2018-06-24 11:25:50.813 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=253]
/var/log/openhab2/openhab.log:4631:2018-06-24 11:25:50.819 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=253], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
/var/log/openhab2/openhab.log:4632:2018-06-24 11:25:50.821 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=null, radius=0, sequence=37, payload=00 00]
/var/log/openhab2/openhab.log:4633:2018-06-24 11:25:50.822 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=NULL, startIndex=0]
/var/log/openhab2/openhab.log:4637:2018-06-24 11:25:50.829 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=254], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 00 00 00]
/var/log/openhab2/openhab.log:4638:2018-06-24 11:25:50.831 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, sequence=37, payload=00 00 00 00 00]
/var/log/openhab2/openhab.log:4639:2018-06-24 11:25:50.832 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]
/var/log/openhab2/openhab.log:4640:2018-06-24 11:25:50.834 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: Node SVC Discovery ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]]
/var/log/openhab2/openhab.log:4641:2018-06-24 11:25:50.835 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000B131242: Neighbor table unchanged
/var/log/openhab2/openhab.log:4642:2018-06-24 11:25:50.836 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: Node SVC Discovery request NEIGHBORS successful. Advanced to null.
/var/log/openhab2/openhab.log:4646:2018-06-24 11:25:50.840 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=253], messageTag=37, status=EMBER_SUCCESS, messageContents=]
/var/log/openhab2/openhab.log:4647:2018-06-24 11:25:50.840 [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_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=253], messageTag=37, status=EMBER_SUCCESS, messageContents=]
/var/log/openhab2/openhab.log:4648:2018-06-24 11:25:50.840 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: Node SVC Discovery running
/var/log/openhab2/openhab.log:4650:2018-06-24 11:25:50.842 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 000D6F000B131242: Node SVC Discovery complete
/var/log/openhab2/openhab.log:4651:2018-06-24 11:25:50.843 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000B131242: Node 0 update
/var/log/openhab2/openhab.log:4652:2018-06-24 11:25:50.844 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 000D6F000B131242: Discovery notification
/var/log/openhab2/openhab.log:4653:2018-06-24 11:25:50.848 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
/var/log/openhab2/openhab.log:4654:2018-06-24 11:25:50.851 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.

It looks good it seems?

How about discovery. I have one Zigbee bulb to play with (Cheapest I could find ) and I’ve turned it on. But nothing has come in the inbox so far.

5iver · June 24, 2018, 5:35pm

Same way you discover any new device in OH… PaperUI big blue dot with a plus sign or Search For Things, or in Habmin> Configuration> Things> magnifying glass with plus sign. Then select the binding you want to start discovery for. If you don’t have auto-approved enabled, you’ll find the discovered Things in the Inbox, which you need to then manually approve.

chris · June 24, 2018, 6:02pm

Yep - at least communications with the dongle is fine,

Enable discovery, then reset the bulb within a few seconds and see what happens…

FunMiles · June 24, 2018, 10:41pm

It’s working perfectly!
Thanks, Chris and Scott!

On the other hand, if the power goes out and comes back on, the light comes on full on even though it was last set to off. The good news is that it does notify openHAB and it shows as full on in the interface.

Is there a way to address that? A rule is one way, but not an elegant one in my view…

FunMiles · June 25, 2018, 10:00pm

Now I’m having a new problem. After not doing any change to the bulb I have, the bulb is not controllable anymore. Sometimes if I disconnect it and then reconnect it, it will rejoin the network and work fine, but I’ve now had more than one occasion where I do that, it comes up as online but is not responding to any control changes.
My bulb is a singled bulb. Do you guys think it’s a problem on the bulb end or elsewhere?

5iver · June 25, 2018, 10:14pm

With one bulb, you’ll need to be within range of the controller, and RF interference could be in play. I don’t think you mentioned which version of the binding you’re running. The latest versions made this controller more stable, but I occasionally need to power cycle and kick off discovery to get a bulb working again.

FunMiles · June 26, 2018, 5:30pm

I thought about the range issue. It was about 7m away in a different room. I moved it closer to the same room. I will report if the loss of connectivity happens again.

I am using a fresh install from apt-get on ubuntu. How do I show the version of the binding?

5iver · June 26, 2018, 5:33pm

In Karaf…

list |grep -i zig

It’s possible your wifi could be interfering, especially if the controller is sitting near to your AP. Setting the channel to 25 may help, especially if your AP is on channel 1.

FunMiles · June 26, 2018, 5:39pm

Here are what I presume are the relevant entries:

208 │ Active   │  80 │ 1.0.11                 │ com.zsmartsystems.zigbee.dongle.ember
211 │ Active   │  80 │ 2.3.0                  │ ZigBee Binding
213 │ Active   │  80 │ 2.3.0                  │ ZigBee Ember Binding

The usb stick is right next to the WiFi. I’ll try the channel suggestion as soon as I have some time to do a bit more testing.

5iver · June 26, 2018, 5:42pm

 15 │ Active   │  80 │ 1.0.12                 │ com.zsmartsystems.zigbee
 16 │ Active   │  80 │ 1.0.12                 │ com.zsmartsystems.zigbee.dongle.ember
 18 │ Active   │  80 │ 2.4.0.201806152142     │ ZigBee Ember Binding
 19 │ Active   │  80 │ 2.4.0.201806152142     │ ZigBee Binding

I’m not on the very latest, but recent. These can be installed manually, but it is much easier to just upgrade to the OH snapshot. Every now and then I still need to rediscover a bulb. GE Links are notorious for this.

FunMiles · June 28, 2018, 1:59am

After moving the bulb much closer, 30h have passed and it’s working still. So it seems to be indeed a radio link issue.

FunMiles · July 11, 2018, 10:59pm

@5iver, how do you re-discover? I had a power outage and I tried everything I could think of. Remove the things and then re-discover them, but my two bulbs are still not responding. If I turn them off, even after 8h, they still show as online while I don’t think they would keep communicating. Do lightbulb have internal batteries?