Zigbee Ember Nortek HUSBZB-1 Issues - Keep Initializing

Add-ons Bindings
, ,
1

So I recently upgraded my openhab to the latest stable release 2.5.9 as I was having issues with the Amazon binding. After doing this I now have issues with my Zigbee Binding which I am using a Nortek HUSBZB-1 as the controller using the Ember EM35x Coordinator.

I noticed the zigbee “things” (including the coordinator) keep cycling between UNKNOWN, INITIALIZING, MISSING HANDLER ERROR, and sometimes go to ONLINE)

Its like the main Ember Coordinator thing keeps reseting causing all the others to go down as well.

I am primarily using this for iris door contact sensors. Model: 1116-S
These have the temperature sensors in as well.

They were working fine before and now none of it is working.

Here is some info I see in the logs:

    2020-10-04 16:59:33.408 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - D0CF5EFFFEC90969:   Starting ZigBee device discovery
2020-10-04 16:59:34.409 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880102697D53: Error initialising device
2020-10-04 16:59:34.409 [INFO ] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102697D53: Channel zigbee:device:44904be9:0017880102697d53:0017880102697D53_11_dimmer failed to initialise device
2020-10-04 16:59:47.274 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0017880102697D53: Starting ZigBee device discovery
2020-10-04 17:00:03.437 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - D0CF5EFFFEC90969: Starting ZigBee device discovery
2020-10-04 17:00:03.437 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - D0CF5EFFFECA9BF7: Starting ZigBee device discovery
2020-10-04 17:00:07.540 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - D0CF5EFFFEB86F75: Starting ZigBee device discovery
2020-10-04 17:01:12.048 [ERROR] [ng.zigbee.handler.ZigBeeThingHandler] - null: Exception creating channels 
2020-10-04 17:01:12.050 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler of thing zigbee:device:44904be9:d0cf5efffeca9bf7 tried updating channel D0CF5EFFFECA9BF7_1_tamper although the handler was already disposed.
2020-10-04 17:01:12.050 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler tried updating the thing status although the handler was already disposed.
2020-10-04 17:01:12.052 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler of thing zigbee:device:44904be9:d0cf5efffeca9bf7 tried updating channel D0CF5EFFFECA9BF7_1_tamper although the handler was already disposed.
2020-10-04 17:01:12.052 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler tried updating the thing status although the handler was already disposed.
2020-10-04 17:01:12.054 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler of thing zigbee:device:44904be9:d0cf5efffeca9bf7 tried updating channel D0CF5EFFFECA9BF7_1_temperature although the handler was already disposed.
2020-10-04 17:01:12.055 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler tried updating the thing status although the handler was already disposed.
2020-10-04 17:01:22.217 [ERROR] [ng.zigbee.handler.ZigBeeThingHandler] - null: Exception creating channels 
2020-10-04 17:01:22.219 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler of thing zigbee:device:44904be9:d0cf5efffeb86f75 tried updating channel D0CF5EFFFEB86F75_1_tamper although the handler was already disposed.
2020-10-04 17:01:22.219 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler tried updating the thing status although the handler was already disposed.
2020-10-04 17:01:22.219 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler of thing zigbee:device:44904be9:d0cf5efffeb86f75 tried updating channel D0CF5EFFFEB86F75_1_tamper although the handler was already disposed.
2020-10-04 17:01:22.220 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ZigBeeThingHandler tried updating the thing status although the handler was already disposed.

I enabled debugging and here is a snippet for a specific Zigbee Thing (Iris Contact Sensor)

2020-10-04 17:25:05.356 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=D0CF5EFFFEC90969 queueTime=28138, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 7443/1, cluster=0000, TID=1E, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-10-04 17:25:05.357 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - D0CF5EFFFEC90969: transactionComplete, state=FAILED, outstanding=0
2020-10-04 17:25:05.357 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - D0CF5EFFFEC90969: transactionComplete exceeded max retries 2
2020-10-04 17:25:05.357 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=D0CF5EFFFEC90969 queueTime=28141, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 7443/1, cluster=0000, TID=1E, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-10-04 17:25:05.357 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=D0CF5EFFFEC90969 queueTime=28141, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 7443/1, cluster=0000, TID=1E, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-10-04 17:25:05.358 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - D0CF5EFFFEC90969: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-10-04 17:25:05.358 [DEBUG] [transaction.ZigBeeTransactionManager] - 7443/1: Sending ZigBeeTransaction [ieeeAddress=D0CF5EFFFEC90969 queueTime=21166, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 7443/1, cluster=0000, TID=26, identifiers=[6]]]
2020-10-04 17:25:05.360 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - D0CF5EFFFEC90969: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=D0CF5EFFFEC90969 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 7443/1, cluster=0000, TID=--, identifiers=[6]]]
2020-10-04 17:25:10.160 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=D0CF5EFFFEC90969 queueTime=25966, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 7443/1, cluster=0000, TID=26, identifiers=[6]]]
2020-10-04 17:25:10.160 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - D0CF5EFFFEC90969: transactionComplete, state=FAILED, outstanding=0
2020-10-04 17:25:10.160 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - D0CF5EFFFEC90969: Added transaction to queue, len=3, transaction=ZigBeeTransaction [ieeeAddress=D0CF5EFFFEC90969 queueTime=25968, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 7443/1, cluster=0000, TID=26, identifiers=[6]]]
2020-10-04 17:25:10.161 [DEBUG] [transaction.ZigBeeTransactionManager] - 7443/1: Sending ZigBeeTransaction [ieeeAddress=D0CF5EFFFEC90969 queueTime=25969, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 7443/1, cluster=0000, TID=26, identifiers=[6]]]
2

From what version? If it was before 2.5 did you read the 2.5 Release notes for breaking changes?

It appears you may have an invalid addon defined causing all addons to reload every minute trying to load the invalid one.

3

I was on 2.4.0 and then I updated to 2.5.0 and then to 2.5.9.
I did not notice anything in either release notes that would cause issues.

So any add-on (binding) could cause issues with all others?
I do not appear to be having issues with my X10 binding at the moment, am I wrong to assume that I would be if they were all reloading like you said?

Thanks for the help.

4

Post the addons.config file from config/org/openhab in your userdata tree. Not the addons.cfg filw that is usually all commented out.

I know restdocs was a major culprit because its location moved in `2.5.

5

Thanks Bruce that helped, I checked out my addons.config and think I found the issue after checking through my log again. Sorry for the delay haven’t had time this week to look at it.

I found this entry : 2020-10-04 22:02:11.029 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-action-mail'

There was a mail item in addons.config. I removed this line and the issue above went away. So one step closer, thank you!

I now have a new issue with my Zigbee items now.

Devices don’t seem to be staying connected or connect at all and my range appears to be severely limited as well, the only other “router” type zigbee device is a lightbulb and it shows connected and “ONLINE”.

I have the iris door contact / temp sensors which only one will connect now. I tried to re-add another one by manually removing and rejoining but it now just shows “Offline - Node has not completed discovery” (Not “Offline - Gone” like before) . I also have a humidity / temp sensor that shows “ONLINE” now but its not updating any of the linked items with info. They stay at NULL.

Here are some log snippets, not sure if they will help.

2020-10-08 20:28:08.343 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:44904be9:0017880102697d53' to inbox.
2020-10-08 20:28:29.041 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880102697D53: Error initialising device
2020-10-08 20:42:57.822 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880102697D53: Error initialising device
2020-10-08 21:00:40.241 [ERROR] [ding.zigbee.internal.ZigBeeDataStore] - 00124B002214EAE1: ZigBee removing network state complete
2020-10-08 21:01:38.971 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:44904be9:00124b002214eae1' to inbox.
2020-10-08 21:14:00.726 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880102697D53: Error initialising device
2020-10-09 00:48:39.397 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880102697D53: Error initialising device
2020-10-09 03:38:08.890 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880102697D53: Error initialising device
2020-10-09 07:11:09.340 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880102697D53: Error initialising device
2020-10-09 07:23:24.682 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880102697D53: Error initialising device

The device ending in ae1 is my SONOFF SNZB-02 temp / humidity sensor and D53 is my Philips Hue bulb.

6

The 2.5 Release nNotes mentioned that as a breaking change. thjat was the v1 mail. It got moved to legacy bindings because there is a v2 mail binding now, since 2.5

7

I must have missed it, Im not using it at this point so I removed it.

8

Did you have restdocs installed? That was a huge culprit. Perhaps post your addons.config.

9

I don’t believe so see addons.config below:

:org.apache.felix.configadmin.revision:=L"9"
action=""
binding="exec,weatherunderground,openweathermap,konnected,network,harmonyhub,plex1,kodi,hue,amazonechocontrol,zigbee,zwave,icloud"
misc=",homekit,ruleengine,gcal1,openhabcloud,market"
package="standard"
persistence="rrd4j,influxdb"
service.pid="org.openhab.addons"
ui="basic,paper,habpanel,homebuilder,cometvisu,habot,habmin"
1 Like
10

Looks good to me Thanks

11

I having problem 2, I thought it was the fault Sonoff SNZB-04, but today I recibe a new unit and i contonue having problems. I pair the new unit but then nothing happens, I also have HUSBZB-1. Can you confim to me that the new sonoff zigbee device are compatible?