The Ember coordinator is used extensively by “a lot” of installations, so I don’t think there is a general problem - it’s the most used coordinator of all the systems I support.
I don’t really know what’s up though - have you looked at the logs?
Hi chris,
Yes this is the reason i bought it!
With “common problem” i mean a problem on MY system that doesn´t let me connect anything with it. Not just a problem with one zigbee device.
Maybe i used the wrong word - as a german I don´t use English in my everyday life very often.
I just activated debug logging for the zigbee binding and will try a few things and give it a look then.
1 Like
Here is the log from openhab2.log since restarting service and activation of debug logging.
I newly tried to scan for new devices and also took an eurotronic spirit to join-mode.
I am not used in reading such logs but i cant see that there is something wrong, just that there seems to be no reaction from the eurotronic that is logged?
2019-12-22 14:22:31.254 [WARN ] [org.apache.karaf.shell.ssh.Activator] - Error starting activator
java.lang.IllegalStateException: Service not tracked for class interface org.osgi.service.cm.ConfigurationAdmin
at org.apache.karaf.util.tracker.BaseActivator.getTrackedService(BaseActivator.java:369) ~[bundleFile:?]
at org.apache.karaf.util.tracker.BaseActivator.ensureStartupConfiguration(BaseActivator.java:154) ~[bundleFile:?]
at org.apache.karaf.shell.ssh.Activator.doStart(Activator.java:96) ~[bundleFile:?]
at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:312) [bundleFile:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_232]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]
2019-12-22 14:22:34.125 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Berlin'.
2019-12-22 14:22:34.129 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'de_DE'.
2019-12-22 14:22:42.226 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2019-12-22 14:22:45.428 [INFO ] [b.core.service.AbstractActiveService] - FritzboxTr064 Refresh Service has been started
2019-12-22 14:22:46.054 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.188.28:8080
2019-12-22 14:22:46.055 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.188.28:8443
2019-12-22 14:22:46.156 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2019-12-22 14:22:46.250 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2019-12-22 14:22:46.307 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2019-12-22 14:22:46.370 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2019-12-22 20:05:37.327 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'hue:0220:1468dc8d:3' to inbox.
2019-12-22 20:44:09.433 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2019-12-22 20:44:09.433 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=6, ackNum=4, reTx=false, data=C7 00 18]
2019-12-22 20:44:09.439 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=7, reTx=false, data=C7 80 18 02]
2019-12-22 20:44:09.440 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=6, ackNum=4, reTx=false, data=C7 00 18]
2019-12-22 20:44:09.441 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
2019-12-22 20:44:10.434 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2019-12-22 20:44:10.435 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=7, ackNum=5, reTx=false, data=C8 00 18]
2019-12-22 20:44:10.441 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=0, reTx=false, data=C8 80 18 02]
2019-12-22 20:44:10.441 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=7, ackNum=5, reTx=false, data=C8 00 18]
2019-12-22 20:44:10.441 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
2019-12-22 20:44:11.436 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2019-12-22 20:44:11.436 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=0, ackNum=6, reTx=false, data=C9 00 18]
2019-12-22 20:44:11.442 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=1, reTx=false, data=C9 80 18 02]
2019-12-22 20:44:11.443 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=0, ackNum=6, reTx=false, data=C9 00 18]
2019-12-22 20:44:11.443 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
2019-12-22 20:44:12.437 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2019-12-22 20:44:12.437 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=1, ackNum=7, reTx=false, data=CA 00 18]
2019-12-22 20:44:12.443 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=2, reTx=false, data=CA 80 18 02]
2019-12-22 20:44:12.443 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=1, ackNum=7, reTx=false, data=CA 00 18]
2019-12-22 20:44:12.444 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
2019-12-22 20:44:13.438 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2019-12-22 20:44:13.438 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=2, ackNum=0, reTx=false, data=CB 00 18]
2019-12-22 20:44:13.445 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=3, reTx=false, data=CB 80 18 02]
2019-12-22 20:44:13.445 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=2, ackNum=0, reTx=false, data=CB 00 18]
2019-12-22 20:44:13.446 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
2019-12-22 20:44:14.439 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2019-12-22 20:44:14.440 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=3, ackNum=1, reTx=false, data=CC 00 18]
2019-12-22 20:44:14.446 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=4, reTx=false, data=CC 80 18 02]
2019-12-22 20:44:14.447 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=3, ackNum=1, reTx=false, data=CC 00 18]
2019-12-22 20:44:14.447 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
2019-12-22 20:44:29.875 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_ember:01380FA4
2019-12-22 20:44:29.876 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.
2019-12-22 20:44:29.877 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.877 [DEBUG] [transaction.ZigBeeTransactionManager] - 65532/0: Sending ZigBeeTransaction [queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=06, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.878 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2019-12-22 20:44:29.879 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=06, permitDuration=60, tcSignificance=true]
2019-12-22 20:44:29.879 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=19, payload=00 3C 01]
2019-12-22 20:44:29.880 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000DD02830: Added transaction to queue, len=1, transaction=ZigBeeTransaction [queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.881 [DEBUG] [transaction.ZigBeeTransactionManager] - 0/0: Sending ZigBeeTransaction [queueTime=1, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.881 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
2019-12-22 20:44:29.882 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]
2019-12-22 20:44:29.882 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=1A, payload=00 3C 01]
2019-12-22 20:44:29.894 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=CC]
2019-12-22 20:44:29.896 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=CC], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]
2019-12-22 20:44:29.896 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=0036, addressMode=null, radius=0, apsSecurity=false, apsCounter=CC, payload=00 3C 01]
2019-12-22 20:44:29.896 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]
2019-12-22 20:44:29.897 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]
2019-12-22 20:44:29.897 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true] ZigBeeTransaction [queueTime=17, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.898 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true] ZigBeeTransaction [queueTime=21, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=06, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.937 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=CD]
2019-12-22 20:44:29.959 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=CD], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]
2019-12-22 20:44:29.959 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=0036, addressMode=null, radius=0, apsSecurity=false, apsCounter=CD, payload=00 3C 01]
2019-12-22 20:44:29.960 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]
2019-12-22 20:44:29.960 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]
2019-12-22 20:44:29.960 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true] ZigBeeTransaction [queueTime=80, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.961 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true] ZigBeeTransaction [queueTime=84, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=06, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.962 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32822, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=CE], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
2019-12-22 20:44:29.962 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=8036, addressMode=null, radius=0, apsSecurity=false, apsCounter=CE, payload=00 00]
2019-12-22 20:44:29.963 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=--, status=SUCCESS]
2019-12-22 20:44:29.963 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=--, status=SUCCESS]
2019-12-22 20:44:29.963 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=--, status=SUCCESS] ZigBeeTransaction [queueTime=83, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.964 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=--, status=SUCCESS] ZigBeeTransaction [queueTime=87, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=06, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.965 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=CD], messageTag=07, status=EMBER_SUCCESS, messageContents=]
2019-12-22 20:44:29.965 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=07 state=RX_ACK
2019-12-22 20:44:29.966 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=07, state=RX_ACK, outstanding=2
2019-12-22 20:44:29.966 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [queueTime=86, state=COMPLETE, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:29.967 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
2019-12-22 20:44:29.967 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000DD02830: transactionComplete COMPLETE 0
2019-12-22 20:44:29.967 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 07 -> RX_ACK == COMPLETE
2019-12-22 20:44:30.820 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=CC], messageTag=06, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-22 20:44:30.821 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=06 state=RX_NAK
2019-12-22 20:44:30.821 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=06, state=RX_NAK, outstanding=1
2019-12-22 20:44:30.821 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [queueTime=944, state=FAILED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=06, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:30.822 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2019-12-22 20:44:30.822 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete FAILED 0
2019-12-22 20:44:30.822 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete exceeded retries 1
2019-12-22 20:44:30.823 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [queueTime=945, state=FAILED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=06, permitDuration=60, tcSignificance=true]]
2019-12-22 20:44:30.823 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 06 -> RX_NAK == FAILED
2019-12-22 20:54:30.070 [WARN ] [shd.server.session.ServerSessionImpl] - exceptionCaught(ServerSessionImpl[openhab@/127.0.0.1:52964])[state=Opened] InterruptedByTimeoutException: null
2019-12-22 21:01:50.243 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_ember:01380FA4
2019-12-22 21:01:50.244 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.
2019-12-22 21:01:50.245 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.245 [DEBUG] [transaction.ZigBeeTransactionManager] - 65532/0: Sending ZigBeeTransaction [queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.246 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2019-12-22 21:01:50.247 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]
2019-12-22 21:01:50.247 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=1B, payload=00 3C 01]
2019-12-22 21:01:50.248 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000DD02830: Added transaction to queue, len=1, transaction=ZigBeeTransaction [queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.249 [DEBUG] [transaction.ZigBeeTransactionManager] - 0/0: Sending ZigBeeTransaction [queueTime=1, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=09, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.249 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
2019-12-22 21:01:50.250 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=09, permitDuration=60, tcSignificance=true]
2019-12-22 21:01:50.250 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=1C, payload=00 3C 01]
2019-12-22 21:01:50.262 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=CF]
2019-12-22 21:01:50.263 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=CF], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]
2019-12-22 21:01:50.263 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=0036, addressMode=null, radius=0, apsSecurity=false, apsCounter=CF, payload=00 3C 01]
2019-12-22 21:01:50.264 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]
2019-12-22 21:01:50.264 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]
2019-12-22 21:01:50.264 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true] ZigBeeTransaction [queueTime=16, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=09, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.265 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true] ZigBeeTransaction [queueTime=20, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.306 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=D0]
2019-12-22 21:01:50.327 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=D0], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]
2019-12-22 21:01:50.328 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=0036, addressMode=null, radius=0, apsSecurity=false, apsCounter=D0, payload=00 3C 01]
2019-12-22 21:01:50.328 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]
2019-12-22 21:01:50.328 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]
2019-12-22 21:01:50.329 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true] ZigBeeTransaction [queueTime=81, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=09, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.329 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true] ZigBeeTransaction [queueTime=84, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.330 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32822, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=D1], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
2019-12-22 21:01:50.330 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=8036, addressMode=null, radius=0, apsSecurity=false, apsCounter=D1, payload=00 00]
2019-12-22 21:01:50.330 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=--, status=SUCCESS]
2019-12-22 21:01:50.331 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=--, status=SUCCESS]
2019-12-22 21:01:50.331 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=--, status=SUCCESS] ZigBeeTransaction [queueTime=83, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=09, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.331 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=--, status=SUCCESS] ZigBeeTransaction [queueTime=86, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.332 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=D0], messageTag=09, status=EMBER_SUCCESS, messageContents=]
2019-12-22 21:01:50.333 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=09 state=RX_ACK
2019-12-22 21:01:50.333 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=09, state=RX_ACK, outstanding=2
2019-12-22 21:01:50.333 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [queueTime=85, state=COMPLETE, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=09, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:50.334 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
2019-12-22 21:01:50.334 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000DD02830: transactionComplete COMPLETE 0
2019-12-22 21:01:50.334 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 09 -> RX_ACK == COMPLETE
2019-12-22 21:01:51.206 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=CF], messageTag=08, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-22 21:01:51.207 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=08 state=RX_NAK
2019-12-22 21:01:51.207 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=08, state=RX_NAK, outstanding=1
2019-12-22 21:01:51.208 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [queueTime=963, state=FAILED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:51.208 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2019-12-22 21:01:51.209 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete FAILED 0
2019-12-22 21:01:51.209 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete exceeded retries 1
2019-12-22 21:01:51.209 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [queueTime=964, state=FAILED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-22 21:01:51.209 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 08 -> RX_NAK == FAILEDUsing the zigbee log viewer it appears to me the coordinator shows a successful join but the Spirit does not get the message. Perhaps factory reset the device?
https://www.cd-jackson.com/index.php/openhab/zigbee-log-viewer
You´re sure? But nothing shows up in the inbox and the devices goes to “Err” (Error) on the display after 1 minute of searching.
Maybe the Problem is this:
2019-12-22 21:34:57.591 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 0A → RX_NAK == FAILED
I dont really know how the zigbee protocol is working, but i wonder if they found another the coordinator fails because of the missing NAK receive? What can i do about that?
And whats the matter of that “Installation Code” i mentioned in my first post? Maybe the problem is that i have to give it an installation code to work? If yes, where to find it?
I’ve just ordered one of these so I can test problems people are having. It should arrive in the next few days I hope.
I will also update the binding to the latest ZigBee libraries - I’d suggest we wait until this is done before chasing this too hard.
Chris is our developer. He will figure it out.
ok thanks to you all! I will keep trying, but also look forward if there is something you´ll find out with help of the hardware device.
I also donated a little bit to you chris, so you don´t have to charge these things from your own money, i think other people here did these before so you can use your money for taking a break of coding and doing holiday vacation or something you like.
I hope there will be more in the future that i can give back to this community!
2 Likes
Thanks Alex.
Hi, Happy new Year!
Are there any News ?
I tried it again and again.
Tried using openhab 2.4 and also 2.5.m2 (which was stated as working in an older thread i found in forum). But everywhere the same Problem: Coordinator is found and stated to be online but can´t find any Zigbee device, neither one of the Eurotronics Thermostats or my Hue Bulb.
Also tried to set up Openhab in a Docker-Container and also in an Debian-VM with passthrough the USB Coordinator activated. Same result everytime.
Last one to go for: I also owned an Raspberry Pi 3 for setting up an home build Mycroft AI. I am going to try it with openhabian installed and connecting the Bitron USB coordinator with it. But that wouldn´t be the way i want to use it in the future.
I have received the Spirit but have not had a lot of time to look at it. I did find that it is very quick to go to sleep once it joins the network and this can cause problems, but until the binding updates are merged I dont want to do too much.
Hopefully at some stage in the near future these will be merged - I’m currently waiting on the distro to be updated though.
Ok thanks, i will keep tracking this.
Just playing around with setting zigbee to discover devices, i ran into an fact i did not register before:
2020-01-05 00:58:47.327 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 1D → RX_ACK == COMPLETE
2020-01-05 00:58:48.224 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=F3], messageTag=1C, status=EMBER_DELIVERY_FAILED, messageContents=]
2020-01-05 00:58:48.224 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=1C state=RX_NAK
2020-01-05 00:58:48.225 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=1C, state=RX_NAK, outstanding=1
2020-01-05 00:58:48.225 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [queueTime=993, state=FAILED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 → 65532/0, cluster=0036, TID=1C, permitDuration=60, tcSignificance=true]]
2020-01-05 00:58:48.225 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2020-01-05 00:58:48.226 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete FAILED 0
2020-01-05 00:58:48.226 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete exceeded retries 1
2020-01-05 00:58:48.226 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [queueTime=994, state=FAILED, sendCnt=1, command=ManagementPermitJoiningRequest [0/0 → 65532/0, cluster=0036, TID=1C, permitDuration=60, tcSignificance=true]]
2020-01-05 00:58:48.227 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 1C → RX_NAK == FAILED
As you can see there are lines which show that something with RX_NAK is failing. Your Log Viewer shows nothing if the filters checkboxes aren´t checked, but when this is the output:
I double checked this and the log is always the same when i trigger a Search for Devices in the Inbox for the Zigbee Binding.
And here the new fact: Its always the same output whether there is any Zigbee Device in Joining mode or not! (Even if the batteries of the Eurotronics are removed!)
So I guess there isn´t any Problem with the Zigbee devices i am trying to connect but like an communication Problem with the Bitron Coordinator.
Wouldn´t this change your mind where to search for Problems? I read a few Threads where there are Problems with the eurotronics and zigbee, but they always seem to have their devices in their inbox which i don´t have.
As I’ve mentioned a few times, I want to wait until the new software is available. There have been a LOT of changes since the current version was release 4 months back. At the moment I am putting this through ZigBee certification with the Ember chipset, and while I can’t really explain what you’re seeing at the moment (although I don’t actually see the log you are referring to so I don’t think you have posted this?), there is little point in me chasing issues when you are running an old version of the software.
Please can we wait until the following is merged -:
Of course I´ll wait for the new libraries to be merged into. Thanks for your work onto that!
But the fact that there is no difference in log between just triggering a discover without any zigbee device reachable (batteries removed!) or triggering a discover with device reachable is something i wanted to be mentioned in the thread just if anyone else is running into that problem (in the future).
I´m going to give it a try with the raspberry pi, just to check if there is some hardware problem or incompatibility or maybe problems with the cp210x kernel module RedHat is delivering.
I am just wondering now if its not a problem with the zigbee binding but with my hardware or OS.
I will reply to this when i am done
Ok, but I have no visibility of the log you mention, so I can’t comment on them. Have you posted the logs anywhere? I might have missed them, but I don’t see them in this thread.
Did you factory reset the device? Removing batteries is not enough.
Reset it by pressing all three buttons while the red LED is on and “Err” is displayed (after unsuccessful join"). It will count from 1 to 10, then reset was successful.
Mine didn’t show up in the logs and did not react to messages until I performed a reset.
1 Like
Hi Martin, Hi Chris!
I just gave it another try with factory resetting the eurotronic before triggering discovery.
Changes nothing for me, but you´re sure that this is the way it had to be done? Factory resetting every time a join fails? Although they are freshly from factory and never were connected to anything before? Cant believe it, but ok i keep trying it with a factory reset before every discover.
Chris: Don´t know why you cannot see my log i posted in my second post before this, i put the relevant part into a blockquote?
Anyway i am going to attach the complete log to this post, just if you want to throw a look into.
The last test i did starts at line 9726, but you can see there that every test before has the same output, just timestamp is different.
edit: sorry cant upload the complete log, because file size is limited to 1048 kb -.- I shortened out a few thousand lines from end of dezember which are just showing the same output as now and always. Go to line 6513 now for my last attempt.openhab[shortened].log (992.3 KB)
Yes.
You must reset a device since you do not know what state it is in. If it partially joined a network, then it will never join another network.
Maybe the Spirit has a way to always reset itself if it fails, but by far the safest and easiest way to include a ZigBee device from a known state is to reset it.
Ok, sorry, I didn’t realise that is what you refer to as a log. That is totally insufficient to understand what is happening. I need a reasonable amount of logging to understand the context and what state things are in - a single message received from the dongle is completely useless - sorry.
I will take a look at the full log you’ve now posted a little later.
So here is what my attempt with the Raspberry Pi brought up:
I installed a freshly copy of openhabian 2.5.0-1 from openhab.org to microsd, powered the raspberry up (just power cord and network connected). Waited a while for it to come up. After it was up and ready i connected the BitronVideo Coordinator to the USB-Port. It came up as /dev/ttyAMA0. Then i looked up the inbox in paperui, which was empty. Tried to add it manually but it doesn´t came online. Next step i listed the loaded kernel modules where the cp210x was missing. Tried to modprobe it, but rans into an error. Then rebooted the Pi, now the kernel module cp210x was loaded from startup (dunno what was wrong with it in first place) and the Coordinator showed up in inbox, i added it and it came online like on my x86-server before.
Next i tried one Eurotronic to join (with a factory reset this time) and it showed up in inbox, firstly as a unknown device (added it, but didn´t came online) so i deleted it and did an discover again, when it showed up i waited until it changed from unknown device to “Eurotronic SPZB0001” and added it then. This time it is shown as online. But on the Device itself the “Boost”-Button never flashed green (which should indicate that a joining attempt is registered) and after a while it shows “Err” as its not properly initiated. Tried to retrigger this by checking the box “initiate Device” in Thing settings. Changed nothing.
So conclusion:On the raspberry Pi i successful the devices can find each other but is not working correctly at all.
So I guess maybe the updated Libraries would fix the problem that i run into in my raspberry Pi setup. But my main problem on my x86-machine seems nothing to do with it as the devices can´t communicate with each other in first place.
I am adding my Log from the openhabian on raspberry setup for further researchs.
openhab.log (117.4 KB)
My guess is that the reason behind this failure is that you have a noisy RF environment. The binding sends 2 Join commands - one to the coordinator itself, and one is broadcast. The one to the coordinator is not required for Ember - it was added to solve a problem with the TI dongle.
However, this still means that join is enabled in the coordinator even if other routers in the network will not be able to enable join. It still means that if your joining device is looking for a network, then the coordinator will allow it to join, so it still should be able to join…
However… The failure to send the broadcast is likely a MAC issue (although I can’t prove that from what I can see). This is normally due to high RF levels not allowing the CSMA algorithm to determine a clear point to transmit, and then the command fails. This is currently the only explanation I can provide - I’m not necessarily saying it’s THE reason, but it is ONE possible reason (but there aren’t too many reasons a broadcast won’t be sent and most of the others are ruled out by the fact that the command was accepted and queued in the first place).