Discovery Failed for Zigbee Binding

Java is 1.8 (not sure exactly what version) and it’s MacOS. I’d be a bit surprised if it’s related to Java or the OS though - I suspect somewhere you’ve got a file that won’t die. Clearly somewhere there’s an incompatibility between the binding that you’re running and the OH runtime.

I could see that for my production install, but I don’t see how this could be the case for a clean install. Is it possible the stick is in an odd state after deleting Things? This first started for me after deleting two Things and rediscovering.

The exceptions in Karaf is interesting to me…

Exception in thread "pool-6375-thread-201" java.lang.IncompatibleClassChangeError: Expected static field org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService.scheduler
        at org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService.nodeDiscovered(ZigBeeDiscoveryService.java:202)
        at org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService.nodeAdded(ZigBeeDiscoveryService.java:208)
        at com.zsmartsystems.zigbee.ZigBeeNetworkManager$6.run(ZigBeeNetworkManager.java:1171)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Exception in thread "pool-6375-thread-202" java.lang.IncompatibleClassChangeError: Expected static field org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService.scheduler
        at org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService.nodeDiscovered(ZigBeeDiscoveryService.java:202)
        at org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService.nodeAdded(ZigBeeDiscoveryService.java:208)
        at com.zsmartsystems.zigbee.ZigBeeNetworkManager$6.run(ZigBeeNetworkManager.java:1171)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

The two of them occur right after starting the binding, the network starts up, and devices are being added in. Kicking off discovery does not cause this exception. Why would there only be two, unless it is somehow related to the two devices I deleted?

2018-03-25 15:42:59.964 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=1, ackNum=2, reTx=false, data=11 00 28]
2018-03-25 15:42:59.964 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspGetNetworkParametersResponse [status=EMBER_SUCCESS, nodeType=EMBER_COORDINATOR, parameters=EmberNetworkParameters [extendedPanId=3DAB5D4A2336BFDE, panId=3330, radioTxPower=0, radioChannel=25, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=0, nwkUpdateId=0, channels=07FFF800]]
2018-03-25 15:42:59.965 [DEBUG] [zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetNetworkParametersResponse [status=EMBER_SUCCESS, nodeType=EMBER_COORDINATOR, parameters=EmberNetworkParameters [extendedPanId=3DAB5D4A2336BFDE, panId=3330, radioTxPower=0, radioChannel=25, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=0, nwkUpdateId=0, channels=07FFF800]]
2018-03-25 15:42:59.965 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue: 1
2018-03-25 15:42:59.966 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
2018-03-25 15:42:59.966 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspGetCurrentSecurityStateRequest []
2018-03-25 15:42:59.967 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=2, ackNum=3, reTx=false, data=12 00 69]
2018-03-25 15:43:00.085 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=3, reTx=false, data=12 80 69 00 74 00 C8 6F FF 0A 00 6F 0D 00]
2018-03-25 15:43:00.086 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=2, ackNum=3, reTx=false, data=12 00 69]
2018-03-25 15:43:00.086 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - RX EZSP: EzspGetCurrentSecurityStateResponse [status=EMBER_SUCCESS, state=EmberCurrentSecurityState [bitmask=[EMBER_HAVE_TRUST_CENTER_LINK_KEY, EMBER_TRUST_CENTER_USES_HASHED_LINK_KEY, EMBER_GLOBAL_LINK_KEY], trustCenterLongAddress=000D6F000AFF6FC8]]
2018-03-25 15:43:00.087 [DEBUG] [s.zigbee.dongle.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
2018-03-25 15:43:00.087 [DEBUG] [zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetCurrentSecurityStateResponse [status=EMBER_SUCCESS, state=EmberCurrentSecurityState [bitmask=[EMBER_HAVE_TRUST_CENTER_LINK_KEY, EMBER_TRUST_CENTER_USES_HASHED_LINK_KEY, EMBER_GLOBAL_LINK_KEY], trustCenterLongAddress=000D6F000AFF6FC8]]
2018-03-25 15:43:00.087 [DEBUG] [zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize done: Initialised false
2018-03-25 15:43:00.087 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Start.
2018-03-25 15:43:00.273 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNetworkManager     ] - 000D6F000AFF6FC8: Node 0 added to the network
2018-03-25 15:43:00.276 [DEBUG] [ab.binding.zigbee.discovery.ZigBeeDiscoveryService] - 000D6F000AFF6FC8: Discovery notification
2018-03-25 15:43:00.276 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-03-25 15:43:00.279 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2018-03-25 15:43:00.280 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNetworkManager     ] - 7CE5240000073901: Node 24511 added to the network
2018-03-25 15:43:00.280 [DEBUG] [ab.binding.zigbee.discovery.ZigBeeDiscoveryService] - 7CE5240000073901: Discovery notification
2018-03-25 15:43:00.281 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-03-25 15:43:00.286 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2018-03-25 15:43:00.287 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNetworkManager     ] - 7CE52400000636F0: Node 57849 added to the network
2018-03-25 15:43:00.287 [DEBUG] [ab.binding.zigbee.discovery.ZigBeeDiscoveryService] - 7CE52400000636F0: Discovery notification
2018-03-25 15:43:00.288 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-03-25 15:43:00.296 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2018-03-25 15:43:00.296 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNetworkManager     ] - 7CE524000013F1F0: Node 16868 added to the network
2018-03-25 15:43:00.296 [DEBUG] [ab.binding.zigbee.discovery.ZigBeeDiscoveryService] - 7CE524000013F1F0: Discovery notification
2018-03-25 15:43:00.297 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-03-25 15:43:00.308 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2018-03-25 15:43:00.308 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNetworkManager     ] - 7CE52400001261EF: Node 53682 added to the network
2018-03-25 15:43:00.309 [DEBUG] [ab.binding.zigbee.discovery.ZigBeeDiscoveryService] - 7CE52400001261EF: Discovery notification
2018-03-25 15:43:00.310 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-03-25 15:43:00.323 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2018-03-25 15:43:00.324 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNetworkManager     ] - 7CE524000013F335: Node 41899 added to the network
2018-03-25 15:43:00.324 [DEBUG] [ab.binding.zigbee.discovery.ZigBeeDiscoveryService] - 7CE524000013F335: Discovery notification
2018-03-25 15:43:00.325 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-03-25 15:43:00.341 [DEBUG] [g.zigbee.internal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.

I don’t think it’s anything to do with the stick. It’s a class error…

Well, this linked to the change in ESH -:

        scheduler.schedule(pollingRunnable, 10, TimeUnit.MILLISECONDS);

It was the definition of scheduler that changed… The error is it was expecting a static field - this field used to be static, and was changed to be non-static. It looks like you have an old ZigBee binding (and I know you’ll say it’s not the case, but that’s where the logging is pointing in my opinion).

openhab> list |grep -i zig
236 │ Active   │  80 │ 2.3.0.201803251536     │ ZigBee Binding
openhab> feature:list |grep -i zig
openhab-binding-zigbee                      │ 2.3.0.SNAPSHOT   │          │ Uninstalled │ openhab-addons-2.3.0-SNAPSHOT        │ ZigBee Binding

Downloaded today. After updating to the latest snapshot (1241), removing the jar from addons, and installing Zigbee through PaperUI, I get the same exceptions in Karaf and when running discovery.

openhab> list |grep -i zig
235 │ Active   │  80 │ 2.3.0.201803251536     │ ZigBee Binding
openhab> feature:list |grep -i zig
openhab-binding-zigbee                      │ 2.3.0.SNAPSHOT   │ x        │ Started     │ openhab-addons-2.3.0-SNAPSHOT        │ ZigBee Binding

Short version… could you try this with a fresh install and configure the network for a dongle that already has devices paired?

Detailed version…

  1. Fresh install of Fedora 27,
  2. a manual install of OH 2.3.0 snapshot 1243 downloaded from here,
  3. installed the Zigbee binding through PaperUI,
  4. add a Ember EM35x coorindinator Thing in Habmin (which looks to have a bug because nothing looks to change after hitting Save, but going back to Things shows the new one),
  5. configure it with the same settings (port, baud, channel, panid, epanid, network key) previously used on the controller

When I do this, the logs look good and nodes are added to the nietwork, but no Things are added. Discovery throws the same error and there are a lot of the exceptions in the Karaf console (probably one for each device). Is it possible this issue has something to do with trying to use the previous network configuration? I don’t have another dongle I could reset to try from a clean state, but I may end up wiping my network to try it from scratch.

I really can’t see how this can be related to the dongle. The dongle has nothing to do with the Java code :confused:

Also, note that ZigBee is totally different to ZWave - wiping a dongle doesn’t really do anything since the dongle doesn’t store the list of devices (or anything) like ZWave. Each device stands on its own once it is in the network - ie once it’s been sent the keys to the network it has access…

If from this you expect that devices can join a coordinator just by setting all this stuff the same as previously, don’t expect it to work. There is something else that you can’t currently set that will scupper such plans (and that’s the security counter).

I’m just trying to come up with a way for you to be able to reproduce the error. I’m not sure if you did a manual install or used apt-get, but from what I’ve seen, this shouldn’t matter. But in your testing of this…

… I was curious if you tried (or could try) doing a discovery on a network that already had devices. That’s currently the only possible difference I can identify, but I don’t have another dongle to setup a new network and see if the error still occurs. I’ve tried several OSs, Java versions, OH installation methods, OH repositories, etc., with the same results. With all the testing I’ve done, I do not see how this issue could possibly be isolated to my systems (… and @ptmuldoon’s). The only constant really being that my dongle was configured each time to use the network that my other devices are on.

It looks to me like the Zigbee binding in the distribution has somehow not yet been recompiled against the updated ESH bundles (!?), or there is some other issue here.

I don’t quite understand what you mean by this. If I use my existing dongle in a fresh OH install, can’t I just use the previous configuration, or do I need to reset all devices and start over? Or is this only the case with a new/replacement dongle?

Manual - I’m on a Mac.

Yes - I do this all the time, but as I said earlier, the coordinator doesn’t actually know if there are devices in the network or not.

As the error is a Java class type error - it’s not related to this though.

To me it looks the other way around - the error says it’s expecting a static field in the ZigBeeDiscovryService, which presumably means it’s not static. The system was changed from static, to not static. So the way I read this, ESH is expecting a static field as it’s still the old complication, and the ZigBee binding is not providing a static field (if that makes sense :wink: ). I’m not 100% sure of this though!

Yes - you can. No problem with this…

Correct - what you can’t do is take another coordinator, type in all the same parameters, and expect that to work - it won’t (yet). This is on my hitlist though so it will be added soon.

That did make sense :slight_smile:. And as expected, using an older version of the binding causes the same errors. Hmmm…

But I just found a way to get rid of the error! I had noticed once that when I reset one of the two bulbs that I had deleted the Things for, it flashed again like it had been paired. In looking in the logs, everything looks normal for these two bulbs, just no handlers. This seemed odd, since they were reset and I hadn’t run discovery but they must have been paired. So, I reset them again, but turned them off right after. I no longer got the exception in Karaf or the log! I restarted the binding, I ran discovery, no exception. As soon as I turn the lights on… exception! Turning them back off does not stop the exception, until I reset the bulbs and then turn them off. I will try pairing another device tomorrow to see if the exception comes back, and put some logs together.

Are you still seeing this issue? It sounded like you were getting it on at least a couple systems. I’m convinced it’s not just me, and I’m baffled why others aren’t reporting it.

@5iver. Scott. Yes I am still getting the error and can try and again this weekend by resetting all bulbs again.

I think/wonder if a hard reset of a bulb is causing an issue and if i pair an unpair from a hue/lightify app first may help.

Ok,

So not much of an update, but I made sure all of my existing Zigbee bulbs are currently 1) paired with another controller, ie… either Hue Hub or Lightify Hub, and 2) also physically powered off. And then after that, running discovery on the my Zigbee stick still gives the error. This is on my main OH2 install.

I can move the stick tomorrow to a new OH2 install and see if that helps. But like Scott, the error continues for me.

Sorry guys, but I don’t think there’s anything I can do at the moment. I can’t reproduce this, and there was absolutely no change to the binding (last change was over a month ago) so I really can’t see how the binding should be at fault given the error started just over a week ago when ESH changed.

The error here is related to Java classes - not the stick management, so all you are doing by removing and adding devices is exercising the discovery which is where the change was made in ESH, but it’s not actually related to the stick.

So I just tried again this morning on my other Clean/Test VM OH2 install and repeated the error

After setting up OH2 the Ember Controller, my first scan work correctly. I then unpaired a bulb from my Lightify Hub and attempted to pair with OH2. The light flashes like it is paired with the controller, but does not appear in either PaperUI or Habmin as being found.

And then when attempting a second device scan, I get the Failed Error again.

I will try and reset OH to an my earlier VM snap shot and maybe try with a different bulb. Just guess, but I’m in the USA and I now these lightify bulbs use the Zigbee HA standard, and not ZLL. Probably nothing to do with it, but it’s trial and error.

Side note. On my clean, fresh OH2 install. I do need seem to install the serial transport binding in order to get the Zigbee stick working. Should the Zigbee binding install that automatically?

feature:install openhab-transport-serial

I may or may not have lots of time today as I wait for my car to be fixed :frowning:

Most bulbs support both. Fundimentally there’s no real difference at the lower communication levels.

I don’t think it’s anything to do with any device, any dongle, etc. The issue is a Java compilation (linking) error. It’s reporting that one part of the code is basically inconsistent with another part.

No - not the binding, but the system should as it’s part of the ZigBee feature -:

Is there a way to test the Zigbee part of this HUSBZB-1 controller with another software to further troubleshoot? I found the software deconz, but couldn’t get their software in Windows to see my controller (probably a driver issue) and also struggling to configure it with Ubuntu on a headless install.

@Chris I know your not seeing the same error as Scott and I. But can you confirm your testing with same/similar hardware and a USB dongle?

BTW, I was able to reproduce the issue in docker, so anyone should be able to see this. And I would expect everyone using 2.3 snapshot would… but have no explanation for how Chris doesn’t.

Either the jar in the repo is somehow not compiled with the updated ESH, or there was some other OH or ESH change that caused this. If I can find time this weekend, I’ll try compiling the jar myself to hopefully eliminate the first possibility.

I use a lot of different hardware - some similar (ie Ember), some not. As I’ve said, this is not related to hardware - it’s a compilation/linker issue (based on the error that Scott has provided, and given that nothing changed in the binding for 5 or 6 weeks now, I believe this is the case).

https://openhab.ci.cloudbees.com/job/openHAB2-Bundles/lastSuccessfulBuild/org.openhab.binding$org.openhab.binding.zigbee/console

The manifest.mf shows an updated version of the binding (2.3.0.201803311310), but does this mean the binding is not being recompiled?
[INFO] Changes detected - recompiling the module!
[INFO] Nothing to compile - all classes are up to date

I would hope upstream changes would be detected and trigger a recompile. Since nothing has changed in the binding, maybe it is not being recompiled against the new ESH? I can’t think of a way to test what version of ESH it was compiled against.

Another interesting test was to spin up a docker with OH 2.2.0 amd64 debian, and dropped in the 2.3.0 snapshot Zigbee binding. No errors came up and discovery worked. (Well, kinda… 14 of 25 devices dribbled in so far… not all in one shot like I had expected.) This leads me to believe that the jar in the repo has still not been compiled against the latest ESH changes.

@chris, could you touch a file and kick off a build? Hopefully that’s possible with your environment setup with the dongle split.

No - this doesn’t work. The trigger is done manually, but I’ve done that a few times already.

To me this does corroborate the theory that the binding hasn’t rebuilt.

I’m not sure. The build doesn’t get kicked off when files are updated - only when I manually start them.

Hopefully we’ll get the new binding sorted in the coming few days.