Zigbee binding

I assume that’s the same error discussed elsewhere - or do you mean this is a linker error or something?

I’m not sure if/where it may have been discussed :slight_smile:. I usually have the most recent, so this should be relatively new.

Ah - your code is out of date. This was changed quite a while back (before 2.4 was released). This was a change in the library a few months back, and then there was an update to the libraries about a week before 2.4 was released to mop everything up…

Edit: If you wait another 5 minutes, the new version with the poll on reconnect should be complete.

OK… sorry for the scare! Eclipse has been tripping me up all day, so par for course…

Build is now complete…

Cool! Now I need to make one of my bulbs drop… :crazy_face:

Can’t you turn off the power and back on again? That’s what I did to test - set the dimmer to some level, power cycled the bulb and when the bulb comes on, it’s at full brightness. 5 or 10 seconds later and it should show this in the UI.

Gotcha!

I don’t think the files are updated though… or I misunderstood the functionality. Lights came on and stayed at 100. UI’s reflected this too, but I was expecting them to dim back to the old state.

This may be related…

2018-12-24 16:33:23.800 [ERROR] [com.zsmartsystems.zigbee.app.discovery.ZigBeeNodeServiceDiscoverer] - 7CE524000013F7EF: Node SVC Discovery: exception: 
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@2eb64d71 rejected from java.util.concurrent.ScheduledThreadPoolExecutor@5ab9f61[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 1023]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533) ~[?:?]
	at com.zsmartsystems.zigbee.ZigBeeNetworkManager.rescheduleTask(ZigBeeNetworkManager.java:585) ~[284:com.zsmartsystems.zigbee:1.1.8]
	at com.zsmartsystems.zigbee.app.discovery.ZigBeeNodeServiceDiscoverer$NodeServiceDiscoveryTask.run(ZigBeeNodeServiceDiscoverer.java:632) [284:com.zsmartsystems.zigbee:1.1.8]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
	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 PR was merged - I can’t see how it can’t be updated.

This will not change the level of the bulbs - it will update the UI to reflect the state - but only if the bulb sends an announce message that is received by the coordinator.

OK… I misunderstood then. I was hoping they would turn themselves off or back to previous level.

It wasn’t considered acceptable for the binding to do that, so updating the UI seems like at least a reasonable compromise - at least the UI should reflect reality.

1 Like

Nice updates Chris, I have installed the latest binding

303 │ Active   │  80 │ 1.1.8                  │ com.zsmartsystems.zigbee.dongl
304 │ Active   │  80 │ 2.5.0.201812242048     │ ZigBee Telegesis Binding
305 │ Active   │  80 │ 1.1.8                  │ com.zsmartsystems.zigbee.dongl
306 │ Active   │  80 │ 2.5.0.201812242048     │ ZigBee CC2531 Binding
307 │ Active   │  80 │ 2.5.0.201812242048     │ ZigBee Ember Binding
308 │ Active   │  80 │ 1.1.8                  │ com.zsmartsystems.zigbee.dongl
309 │ Active   │  80 │ 2.5.0.201812242048     │ ZigBee Binding
310 │ Active   │  80 │ 1.1.8                  │ com.zsmartsystems.zigbee
311 │ Active   │  80 │ 1.1.8                  │ com.zsmartsystems.zigbee.dongl
312 │ Active   │  80 │ 2.5.0.201812242048     │ ZigBee XBee Binding

Is it still supposed to do a neighbor search every 5 minutes or so? I set the coordinator to 1 day aging.

2018-12-25 09:13:43.563 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000247ECE1: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT]
2018-12-25 09:13:43.567 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000247ECE1: Node SVC Discovery: request NEIGHBORS failed. Retry 7, wait 18744ms before retry.

The problem is that when i push the “update/pair” button on the xiaomi the device leaves and never comes back.

2018-12-25 09:18:05.571 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspChildJoinHandler [index=0, joining=false, childId=13666, childEui64=00158D000247ECE1, childType=EMBER_SLEEPY_END_DEVICE]
2018-12-25 09:18:05.576 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D000247ECE1: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 13666.
2018-12-25 09:18:05.579 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000247ECE1: Polling stopped
2018-12-25 09:18:05.580 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00158D000247ECE1: Device status updated. NWK=13666
2018-12-25 09:18:05.581 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspTrustCenterJoinHandler [newNodeId=13666, newNodeEui64=00158D000247ECE1, status=EMBER_DEVICE_LEFT, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=65535]
2018-12-25 09:18:05.583 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D000247ECE1: Node 13666 update
2018-12-25 09:18:05.583 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000247ECE1: Polling initialised at 7751732ms
2018-12-25 09:18:05.586 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D000247ECE1: nodeStatusUpdate - node status is DEVICE_LEFT, network address is 13666.
2018-12-25 09:18:05.589 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 00158D000247ECE1: Node state updated from ONLINE to OFFLINE
2018-12-25 09:18:05.589 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000247ECE1: Node updated - ZigBeeNode [stateONLINE, IEEE=00158D000247ECE1, NWK=3562, Type=END_DEVICE]
2018-12-25 09:18:05.593 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D000247ECE1: Node 13666 update
2018-12-25 09:18:05.602 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-12-25 09:18:05.683 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2018-12-25 09:18:05.688 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000247ECE1: Node updated - ZigBeeNode [stateOFFLINE, IEEE=00158D000247ECE1, NWK=3562, Type=END_DEVICE]
2018-12-25 09:18:05.702 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-12-25 09:18:05.755 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2018-12-25 09:18:05.757 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000247ECE1: Polling stopped
2018-12-25 09:18:05.759 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000247ECE1: Polling initialised at 7660604ms

Polling time is increased but it still does a neighbor search every few minutes.

EDIT: If I dont push that button, the device seems to live on and sends reports. And the neighbor search continues to fail until the device wakes up once an hour and sends a response.

Yes - this will not impact the neighbor updates.

Did you rejoin the device to the network first - ie it would have aged out previously. Pressing the button will make it communicate with the coordinator which will tell it to rejoin, and the device doesn’t comply with this. If you join the device after the update, is it still doing this?

Polling time was not changed in this version. I’m assuming the polling you talk about is the polling you see from the binding?

For some reason I cant get the lastest binding installed using @5iver script. It does download both the lib and the binding, but only the lib is getting installed.
I get this error in the log:

2018-12-25 15:02:59.964 [WARN ] [ng.zigbee.handler.ZigBeeThingHandler] - null: Polling aborted due to exception 

java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@784d82 rejected from java.util.concurrent.ScheduledThreadPoolExecutor@19363f4[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 75]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533) ~[?:?]
	at com.zsmartsystems.zigbee.ZigBeeNetworkManager.scheduleTask(ZigBeeNetworkManager.java:559) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.transaction.ZigBeeTransaction.sendTransaction(ZigBeeTransaction.java:69) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.ZigBeeNetworkManager.sendTransaction(ZigBeeNetworkManager.java:1439) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.ZigBeeNode.sendTransaction(ZigBeeNode.java:775) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.ZigBeeEndpoint.sendTransaction(ZigBeeEndpoint.java:501) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.zcl.ZclCluster.send(ZclCluster.java:158) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.zcl.ZclCluster.read(ZclCluster.java:174) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.zcl.ZclCluster.read(ZclCluster.java:184) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.zcl.ZclCluster.readSync(ZclCluster.java:233) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at com.zsmartsystems.zigbee.zcl.clusters.ZclOnOffCluster.getOnOff(ZclOnOffCluster.java:136) ~[302:com.zsmartsystems.zigbee:1.1.6]
	at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchOnoff.handleRefresh(ZigBeeConverterSwitchOnoff.java:115) ~[307:org.openhab.binding.zigbee:2.4.0]
	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$2.run(ZigBeeThingHandler.java:443) [307:org.openhab.binding.zigbee:2.4.0]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
	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) [?:?]

And this is what´s installed:

openhab> bundle:list -s |grep -i zig
313 x Active   x  80 x 1.1.8                  x com.zsmartsystems.zigbee.dongle.telegesis
314 x Active   x  80 x 1.1.8                  x com.zsmartsystems.zigbee.dongle.xbee
315 x Active   x  80 x 1.1.8                  x com.zsmartsystems.zigbee
316 x Active   x  80 x 1.1.8                  x com.zsmartsystems.zigbee.dongle.cc2531
317 x Active   x  80 x 1.1.8                  x com.zsmartsystems.zigbee.dongle.ember
openhab>

No binding… Hmm…
The binding is in the addons folder allright.

The reason appears to be that you are using an older version of the script, before the CI server move. I’ll add a check in the script to compare to latest, download if newer, and then restart. But that will be low in the backlog. For now, get the latest.

Thx Scott… I had a feeling you have changed something, but github said it hasn´t changed in 2 months. So I should be using the latest… Anyway, I grapped a fresh copy and ran it… Now I get this error:

[17:25:33] openhabian@openHABianPi:/srv/openhab2-addons$ sudo -u openhab bash zzManualInstaller.sh
This script must be copied to the $OPENHAB_HOME/addons directory before running it
[17:25:37] openhabian@openHABianPi:/srv/openhab2-addons$

Did you change the previous directory? usually I use /srv/openhab2-addons directory, which is where I ran the script last time I ran it.

I have not idea where this $openhab_home/addons directory is if it´s not the /srv/openhab2-addons

Try /usr/share/openhab2/addons/. The script no longer accesses Karaf through ssh but with the /runtime/bin/client script, and finds it using a relative path from addons. This change went in around the same time as the CI server update, and nobody else has reported an issue.

Yep, I just found it as well… But as said, last time I ran the script, it was from the srv/openhab2-addons.
Guess I´ll just have to get used to use usr/share/openhab2/addons from now :slight_smile:

Script working, and I got the zigbee updated.

I have tried to reproduce the issue, and pressing the small button only throws the device out if the neighbor search just have succeeded, right before it starts to do another search. I’m gonna wait and see if the device comes back online again in an hour or so when the device sends out its hourly update.

I have also started to get this error in the log, not sure if it’s an issue though. I’m still getting the reports.

2018-12-26 08:44:07.525 [DEBUG] [s.zigbee.dongle.ember.ezsp.EzspFrame] - Error creating instance of EzspFrame
java.lang.reflect.InvocationTargetException: null
        at sun.reflect.GeneratedConstructorAccessor400.newInstance(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[?:?]
        at com.zsmartsystems.zigbee.dongle.ember.ezsp.EzspFrame.createHandler(EzspFrame.java:404) [305:com.zsmartsystems.zigbee.dongle.ember:1.1.8]
        at com.zsmartsystems.zigbee.dongle.ember.internal.ash.AshFrameHandler$1.run(AshFrameHandler.java:196) [305:com.zsmartsystems.zigbee.dongle.ember:1.1.8]
Caused by: java.lang.ArrayIndexOutOfBoundsException: 76
        at com.zsmartsystems.zigbee.dongle.ember.internal.serializer.EzspDeserializer.deserializeUInt8(EzspDeserializer.java:77) ~[?:?]
        at com.zsmartsystems.zigbee.dongle.ember.internal.serializer.EzspDeserializer.deserializeUInt8Array(EzspDeserializer.java:124) ~[?:?]
        at com.zsmartsystems.zigbee.dongle.ember.ezsp.command.EzspGpepIncomingMessageHandler.<init>(EzspGpepIncomingMessageHandler.java:142) ~[?:?]
        ... 5 more

I have created a PR yesterday that will allow disabling of the mesh info update, so this might also help you.

Please can you provide a bit more of the log - ie a few seconds of data from before the event so I an see what it was trying to send.