Zigbee binding

It seems to happen randomly, once or twice a day. Nothing’s being restarted as far as I can tell.

Ok, I suspect it’s a timing issue and the processor simply needs synchronisation. I’ve created a PR -:

Hi @chris
Did you manage to get some time to play with the Trust motion sensor?
I just come home from vacation to find all my zigbee not responding. After an reboot of the Rpi, my Philips hue things went online, but I cant get the Trust motion sensor to get online again.

No - I didn’t bother as I thought you said it was working and I only bought it for that purpose. Maybe I missed something?

I does almost work.
First problem. It doesn´t release the trigger. You mentioned something about this beeing a “feature” of zigbee or something like that.
Other problem, mentioned above. IT´s offline now, and I dont know why. I can get it online for some reason, (havn´t tried remove it though).

@chris I got my new ZigBee stick now, and it is the BitronVideo with Ember EM35X inside. It is recognized, I added it as a Thing (it automatically determined baud rate 57600 and software flow control), but then it shows up as “Offline” in Things and when I click on it, it says “Status: OFFLINE Bad response received from dongle” in the status part.

I enabled debugging, remove the device and readded it to capture a full log of it being added. The log is here:

https://users.own-hero.net/~decoder/ember.txt

Thanks in advance for any help :slight_smile:

Edit: I thought this could be related to PR 257 (Set default link key), so I built the bindings from source and tried them out, but I still see the related error:

2018-09-19 16:21:26.368 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=FFFF000000000000]]
2018-09-19 16:21:26.371 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - Error during retrieval of security parameters: EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=FFFF000000000000]]

The log is too short - it doesn’t have the initialisation of the dongle - this is done in two parts - the initialisation (which is done) and the sartup, which is not in the log. The log finishes at the end of the initialisation phase.

I also think you are not using the latest binding. So, please try the latest binding from the last day or two, and if it’s still not working, provide a longer log and I’ll have a look.

Cheers
Chris

@chris this was really all that was in the log, the log ended there, and nothing else happened. I can retry now with the latest binding. Is there a preferred way to get it into OpenHAB? I have the jars all compiled here and can copy them into the directory, but there might be a better way to do this? (Sorry, new to this part). Thanks!

@chris I think I managed to upgrade the bindings, bundle:list shows me:

203 │ Active   │  80 │ 2.4.0.201809191348     │ ZigBee Binding
204 │ Active   │  80 │ 2.4.0.201809191348     │ ZigBee CC2531 Binding
205 │ Active   │  80 │ 2.4.0.201809191348     │ ZigBee Ember Binding
206 │ Active   │  80 │ 2.4.0.201809191348     │ ZigBee Telegesis Binding
207 │ Active   │  80 │ 2.4.0.201809191348     │ ZigBee XBee Binding

I deleted the device before starting, rebooted without the device being plugged in, then tailed the log, plugged in the device, added it as a thing. Same error though. Full log is here:

https://users.own-hero.net/~decoder/ember2.txt

There is nothing more following in the log even after waiting for a while.

I guess your log is somehow limited to only ZigBee data and this is why we don’t see the error which will be logged from the framework.

There is a bug in the main zigbee framework that is preventing your dongle joining. Give me a day or two to fix this (I’m on holiday at the moment so have limited time) - if I get a chance I will do it tomorrow.

@chris Thanks, much appreciated! If you need anything else, just let me know. Enjoy your holiday :slight_smile:

Thanks. I’m pretty sure I know what the issue is and it’s a simple issue - I just want to think about it a little more before I make the change, just in case. I have an Ember stick with me so will try and do a quick test before I do the release.

@chris Thanks. I can now also easily compile any changes locally here and update to do that for testing, if required :slight_smile:

Well, if you want to try a test, then look at line 383 in ZigBeeCoordinator - this should be a return statement - change this to a break statement and (hopefully!) it should work (you might also need to comment out the updateStatus in line 382 - at least it won’t hurt to do this as well).

This is not the right solution, but it is a workaround without having to compile the libraries. Let me know how this goes…

@chris I tried that, re-added the stick and as expected, it doesn’t show the “Bad response” error anymore, but it remains in the UNKNOWN state and does not seem to discover any devices. I ran two discovery sweeps but it didn’t find the bulb. Log is here:

https://users.own-hero.net/~decoder/ember3.txt

From a quick look, it looks ok, but the dongle has not come up for some reason. I would try to restart to see if it helps as I have seen some issues with the dongle initialising (although I thought this should be resolved already). If that doesn’t fix it, I’ll take another look at the log in the morning.

I tried quite a few things now, rebooting, reattaching the stick, resetting the stick, unfortunately nothing helped. I also explicitly selected a channel because the log seemed to indicate that it considered the channel invalid, but that didn’t help either, the stick remains in UNKNOWN state.

I’ll wait for your advise then and check back tomorrow :slight_smile:

@chris Fwiw, I managed to bring the device online, but only by hacking around in the source further. First of all, I manually selected a channel (11) and restarted the device. That seemed to do something different and in the logs I then found more, including this:

2018-09-20 01:56:04.746 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspFormNetworkRequest [parameters=EmberNetworkParameters [extendedPanId=9718C936F401670F, panId=65535, radioTxPower=255, radioChannel=11, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=65535, nwkUpdateId=0, channels=00000800]]
2018-09-20 01:56:04.749 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=1, ackNum=4, reTx=false, data=93 00 1E 0F 67 01 F4 36 C9 18 97 FF FF FF 0B 00 FF FF 00 00 08 00 00]
2018-09-20 01:56:04.860 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=2, reTx=false, data=93 80 1E 70]
2018-09-20 01:56:04.864 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=1, ackNum=4, reTx=false, data=93 00 1E 0F 67 01 F4 36 C9 18 97 FF FF FF 0B 00 FF FF 00 00 08 00 00]
2018-09-20 01:56:04.868 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspFormNetworkResponse [status=EMBER_INVALID_CALL]

It seems that panID was always being set to 65535, even though I entered different values. I made a change in ZigBeeCoordinatorHandler.java around line 147 to set it to 0xfffe instead because the logs showed it was executing that branch and using 0xffff there though. That was just a guess, but the right one apparently: It seems that the device does not like 0xffff as a panId.

After I made that change and yet again reinitialized the device, the device came online. I then searched for the bulb (the Innr one) and it was found, colors, switching, etc. all works!

I think we just need to figure out now what steps are required to properly initialize this stick from the start. I’ll be happy to help with that tomorrow and investigate further, for now I need some sleep :wink:

I will try and find some time to look through the log properly. The initialisation procedure in the libraries I’m very confident of as it’s exercised regularly, and used in a number of solutions. I don’t tend to initialise through the binding very often though, so the setting of the options could be incorrect here… I’ve just noticed that the binding isn’t setting the random PANID if set to 65535, which is the AUTO setting - I’ll change this to 0 in the XML and this would also solve your issue with the PANID.

This may then be the only issue by the looks of it.

If you fancy trying this all again from scratch, I’d suggest to delete the coordinator thing and add it back. I think this will likely work straight away as the default for the PANID is 0, but I guess you changed it to AUTO when things weren’t working initially?

Thanks for spending the time to help with this - as I say, it’s an area I don’t tend to test so often within the binding as most of my low level testing is done directly on the libraries with a console application :wink: .

For reference -:

@chris Thanks for taking the time. In fact, I tried to set PANID to various values (0, Auto and values chosen by fair dice roll) through the UI but it would ignore them and always use 65535 which is why I started modifying the source. It might be a UI problem of course.

PANID was not the only problem though. Before that, the channel was not explicitly specified and that also caused an error until I set it to channel 11 (this is the ember3 log). I also noticed another potential error source: When I set the Power mode from “Normal” to “Boost” it also gave me an error (again on the EzspFormNetworkRequest) until I switched it back to “Normal”. If I remember correctly, “Boost” was the default selected in the UI.

I can do some more testing next week, but this weekend I need the lights to work :wink: It sounds to me like it is mostly a UI/default value issue though and that the stick I have is sensitive to some values and refuses to work when any of the parameters don’t seem ok.