Zigbee binding

I know… But I have not seen anyone using another coordinator mentioning the same problem with loosing communication to the coordinator in the same simular way. Ofcouse there could be threads and messages which I havn´t seen. It´s just that the issue and symptoms looks very simular, and the trick by rebooting seems to fix it for a while.
I my situation things went really bad last time, cause the debug log stopped as well, (the log I´d post a link to where you replied with a theory about lack of resources on my system).
After next reboot, the coordinator as well as 3 out of 4 devices came online and was running fine again, and debug logging continued.
The fourth device (The Trust motion sensor) I had to hard-reset and discover/include again, cause it was stated as offline and “not finished discovery”, even though it had been running fine untill I lost communication. I couldn´t fix it without deleting it and re-add it.
But my main concern is regarding the coordinator. I couldn´t care about the devices, if the coordinator isn´t running. The coordinator is the most important device, I believe.

Really? I guess you just haven’t looked then :wink: .

The following issue covers Telegesis, TI and Ember -:

Sorry to be an arse, but this is exactly what I’m referring to above - you simply cannot assume that they are the same issue, and this is why I’m picky about asking for logs etc. The symptoms are “the binding stopped working, and I restarted it and it worked again for a while”. Really, nearly every possibly bug could be summarised by this.

And again, this issue is likely something different, so you can’t assume it’s the same! As I said when looking at that log, I need to get further logs to try and build up a picture of what happened. It’s really common to get a single log, and then people saying “oh, and I have the same problem”. Sorry to keep pushing this point, but logfiles are really needed to show what is happening and reports like “the same thing happened again” is really of no use at all.

Sorry to be a pain (again :wink: ).

@chris I am having some weird behaviour with a rule. Could it be that during the ramp up in light intensity when switching on dimmable lights, that the actual transient brightness value is reflected in OH? Just changed to the nightly release.

Point in case: My rule switches off switchable lights when a dimmable light in the room gets below 50%. Although I am switching the dimmable light on to 100%, it still seems to trigger the rule while it switches on.

Yes - this is definitely possible. The reporting is set to once per second, so it means that if you have a transition time of (say) 3 seconds, you will get reports every 33% (of course it won’t be this exact, but you will get 2 or 3 reports during the transition).

It’s driving me nuts. I’ll toss the rule and give the switchable lights dummy dimmers that can then trigger a rule to either switch them on or off.

No pain, Chris…
I´m just trying to look at different perspectives from “outside” using reports from other users. I know it may not be the cause, but at least I´m keeping focus untill the issue can be eliminated :slight_smile:

Hi Chris - which module would you want debugging enabled for? I had debugging on during the issue for org.openhab.binding.zigbee. I’m attaching a copy of a startup / shutdown where this issue occured and captures all of the binding debug logging. If there is a better logging for me to enable just let me know and next time (lets hope never) I encounter this issue I can try to be of more help with even better logging. I do know the issue first occurred around midday yesterday. I can try to look for more logging around that event but because I didn’t have debugging on at that time I’m not sure it would help. I’ll look at setting up zigbee debugging to its own file and leaving it on longterm in the future so I can be ready. Thanks again for all of your help with this / all of the work you put in here.

Ember null issue.txt.json (84.0 KB)

Both the binding and the libraries are required.

Strange - there is nothing at all logged in the file you provided earlier :confounded:

Yes, this log also has no logging from the libraries and really this is needed. Please take a look at the binding documentation as it describes the required logging.

Thanks.

Yeah - figures. I never had com.zsmartsystems.zigbee on for long term due to its verbosity so of course it would be the useful one :slight_smile: I’ll get this going out to its own file and leave it on should I encounter any other issues. Thank you!

1 Like

@chris
A new situation here.
Suddenly my Trust motion sensor just went offline for no reason at all, (or no obvious reason. I wasn´t at home, so noone was fiddling with the setup or the Rpi). This is openhab.log:

2018-10-25 14:17:32.352 [hingStatusInfoChangedEvent] - 'zigbee:device:4beca465:00158d00019533d3' changed from ONLINE to OFFLINE

The new situation:
It stays offline untill:

2018-10-25 20:54:56.879 [hingStatusInfoChangedEvent] - 'zigbee:device:4beca465:00158d00019533d3' changed from OFFLINE to ONLINE

This is the exact time I enter my office, where the montion sensor is placed. But my Wife have been in the office untill almost 15:00 o’clock.

This Trust motion sensor device has never been been able to get back online by itself, when it has turned into offline status. So this is pretty new situation to me.

Second:
My Hue motion sensor stopped triggeren (well it does trigger from it light, but Openhab does not receive anything) since 10:30.56 this morning.
Hue dimmer Switch as well as Osram plug also doesnt respond… (I dont have a rule to check when they trigger since I do it manually. But it was working untill shortly after midnight).

So status right now.
All four devices has status ONLINE.
Trust sensor is working.
Hue motion sensor, Hue dimmer switch and Osram plug does no longer respond.

These are the zigbee debug log files sincce 00:35 today:



Hope you can make any use of this.

Arrrgh, damit…
Now Philips Hue motion sensor, Philips Hue Dimmer Switch and Osram plug is working fine again. And I have not changed anything, except I added a TP-Link Smart plug (WiFI) a few minutes ago.

What the heck is going on. It has never been like this before.

Hi @chris, it has been a while… I was out with other topics and I could not test the changes. I confirm it is working correcty (assuming it is the ‘extend_static_type’ branch in your repository :slight_smile: )

Added this line to discovery.txt:

xiaomi_lumisensorht,modelId=lumi.sensor_ht

And the file ESH-INF/thing/xiaomi/lumisensorht.xml:

<?xml version="1.0" encoding="UTF-8"?>
<thing:thing-descriptions bindingId="zigbee"
        xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
        xmlns:thing="http://eclipse.org/smarthome/schemas/thing-description/v1.0.0"
        xsi:schemaLocation="http://eclipse.org/smarthome/schemas/thing-description/v1.0.0 http://eclipse.org/smarthome/schemas/thing-description-1.0.0.xsd">

        <thing-type id="xiaomi_lumisensorht">
                <label>Xiaomi Temperature and Humidity Sensor</label>
                <description>Xiaomi Temperature and Humidity Sensor</description>

                <channels>
                        <channel id="temperature" typeId="measurement_temperature">
                                <properties>
                                        <property name="zigbee_endpoint">1</property>
                                        <property name="zigbee_inputclusters">1026</property>
                                </properties>
                        </channel>
                        <channel id="humidity" typeId="measurement_relativehumidity">
                                <properties>
                                        <property name="zigbee_endpoint">1</property>
                                        <property name="zigbee_inputclusters">1029</property>
                                </properties>
                        </channel>
                </channels>

                <properties>
                        <property name="vendor">Xiaomi</property>
                        <property name="modelId">lumi.sensor_ht</property>
                        <property name="zigbee_logicaltype">END_DEVICE</property>
                </properties>

                <representation-property>zigbee_macaddress</representation-property>

                <config-description>
                        <parameter name="zigbee_macaddress" type="text" readOnly="true" required="true">
                                <label>MAC Address</label>
                        </parameter>
                </config-description>
        </thing-type>
</thing:thing-descriptions>

I will now try the two button switch, but I think it will not work as these mostly fail to even report the node descriptor.

Best Regards,
Pedro

“good” news - I had my system drop out on me again in what I believe is the same error - I see in the log the null pointer error. Just as last time I did a cache clear to get it to come back - a normal restart didn’t do any good. Good news though - I got the logging you wanted for a full start and shutdown. :slight_smile:

zigbee.log.json (218.1 KB)

Thanks. This error is definitely not related to the other stopping of the binding issues. This is a startup issue only. There are two errors and they are probably related - firstly there is a failed checksum on a message the binding receives from the stick, then the stick doesn’t respond to a request for some information about its configuration, and this is what causes the error. I’ll have a look at correcting this, but this can only happen on startup at least.

Thanks @jfrank1845

FTR the following PR ought to solve this issue -:

The problem was that during initialisation, the dongle address is not known, and if an incoming frame is received at this time, there is an exception, and this in turn stops the ASH layer working.

The above PR solves the problem in two ways - it doesn’t process received frames until the stack has completed initialising, thus solving the root cause of the problem, but it also catches the exception in a better place to prevent the ASH layer hanging if this had have happened.

It will likely be a month or so before this flows into the binding unless you want to update using @5iver’s update script in which case it will likely be available in the next week when I do an update of the low level libraries.

1 Like

I am writing a rule that sends commands to lamps. I want to avoid superfluous air time. Does the binding check whether a command needs to be sent, before it broadcasts something, or do I need to check for that myself? E.g. sending “ON” to a lamp that already is on.

No - it doesn’t try and be smart. I know that if I were to add a check to not send commands if the state didn’t change, people would likely complain when things get out of sync :wink:

1 Like

Has anyone tried binding the Hampton bay universal ceiling fan control with wink capability yet? I saw that they were finally able to get it working with smartthings and has.

This is what I get when discovering the device if it helps at all. It is the hampton bay zigbee universal ceiling fan control.

2018-11-03 10:45:58.845 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A30000274347: Discovery: Starting discovery for existing device zigbee:device:166c7bd197e:0022a30000274347

2018-11-03 10:45:58.854 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_ember:166c7bd197e

2018-11-03 10:45:58.860 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.

2018-11-03 10:45:58.866 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=00, permitDuration=60, tcSignificance=true]

2018-11-03 10:45:58.867 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A30000274347: Starting ZigBee device discovery

2018-11-03 10:45:58.874 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, sequence=0, payload=00 3C 01]

2018-11-03 10:45:58.877 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A30000274347: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:166c7bd197e

2018-11-03 10:45:58.883 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendBroadcastRequest [destination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=0], radius=31, messageTag=0, messageContents=00 3C 01]

2018-11-03 10:45:58.891 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:166c7bd197e:0022a30000274347' to inbox.

2018-11-03 10:45:58.896 [home.event.InboxAddedEvent] - Discovery Result with UID 'zigbee:device:166c7bd197e:0022a30000274347' has been added.

2018-11-03 10:45:58.903 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A30000274347: Node discovery not complete

2018-11-03 10:45:58.917 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=01, permitDuration=60, tcSignificance=true]

2018-11-03 10:45:58.920 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, sequence=1, payload=00 3C 01]

2018-11-03 10:45:58.923 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [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_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=1], messageTag=1, messageContents=00 3C 01]

2018-11-03 10:45:59.037 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=57]

2018-11-03 10:45:59.038 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=57]

2018-11-03 10:45:59.051 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: 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=57], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]

2018-11-03 10:45:59.053 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=null, radius=0, sequence=0, payload=00 3C 01]

2018-11-03 10:45:59.055 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=NULL, permitDuration=60, tcSignificance=true]

2018-11-03 10:45:59.178 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=58]

2018-11-03 10:45:59.179 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=58]

2018-11-03 10:45:59.188 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: 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=58], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]

2018-11-03 10:45:59.191 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=null, radius=0, sequence=1, payload=00 3C 01]

2018-11-03 10:45:59.193 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=NULL, permitDuration=60, tcSignificance=true]

2018-11-03 10:45:59.202 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: 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=59], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]

2018-11-03 10:45:59.203 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, sequence=1, payload=00 00]

2018-11-03 10:45:59.205 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS]

2018-11-03 10:45:59.213 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: 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_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=58], messageTag=1, status=EMBER_SUCCESS, messageContents=]

2018-11-03 10:45:59.215 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: 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_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=58], messageTag=1, status=EMBER_SUCCESS, messageContents=]

2018-11-03 10:45:59.967 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_MULTICAST_WITH_ALIAS, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=57], messageTag=0, status=EMBER_SUCCESS, messageContents=]

2018-11-03 10:45:59.972 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_MULTICAST_WITH_ALIAS, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=57], messageTag=0, status=EMBER_SUCCESS, messageContents=]

2018-11-03 10:46:02.645 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0022A30000274347: Node SVC Discovery running

2018-11-03 10:46:02.648 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 36754/0, cluster=0003, TID=02, nwkAddrOfInterest=36754]

2018-11-03 10:46:02.652 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=36754/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, sequence=2, payload=00 92 8F]

2018-11-03 10:46:02.655 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=36754, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=2], messageTag=2, messageContents=00 92 8F]

2018-11-03 10:46:02.790 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=60]

2018-11-03 10:46:02.793 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=60]

2018-11-03 10:46:07.484 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=36754, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=60], messageTag=2, status=EMBER_DELIVERY_FAILED, messageContents=]

2018-11-03 10:46:07.487 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=36754, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=60], messageTag=2, status=EMBER_DELIVERY_FAILED, messageContents=]


Hi Chris - just wanted to follow up to see when your next release may be. My issue with the packet messing up my adapter on startup is now seemingly every startup since I’ve joined some motion sensors. I’ve been watching the releases on GitHub from the above link. let me know If I should be looking somewhere else. Thanks !