smitopher
(Christopher Smith)
October 26, 2021, 10:12pm
1
Platform information:
Hardware:x86_64/4Gb/128Gb
OS: Ubuntu 20.04
Java Runtime Environment: OpenJDK 11
openHAB version: 3.2 Snapshot
Issue of the topic:
I have setup 2 Yale Assue SL locks with the Zigbee module
Adding them to OH was straightforward
The lock responds very slowly, when it does
OH does not update when the lock is manually operated
I set the zigbee logging to debug and it’s very verbose
I have 18 Leviton zigbee dimmers and switches so they generate a lot log noise.
Any suggestion on how to filter just for the Locks?
The lock xml
000D6F0010C99F27.xml (106.1 KB)
Log sample
ohlog.log (105.9 KB)
smitopher
(Christopher Smith)
October 26, 2021, 10:15pm
2
Any info I can use when contacting Yale support will also be useful
hmerk
(Hans-Jörg Merk)
October 26, 2021, 10:38pm
3
Could you please post the full Java version.
From your given information, it looks like an unrecommended version, which could lead to your bad performance…
Zulu 11 would be the right choice.
smitopher
(Christopher Smith)
October 27, 2021, 2:14pm
4
:~$ java -version
openjdk version “11.0.11” 2021-04-20
OpenJDK Runtime Environment (build 11.0.11+9-Ubuntu-0ubuntu2.20.04)
OpenJDK 64-Bit Server VM (build 11.0.11+9-Ubuntu-0ubuntu2.20.04, mixed mode, sharing)
I’m pretty sure that OpenJDK is just as supported and preformat as Zulu.
My issue is with the Yale Assure SL lock with the Zigbee module installed
hmerk
(Hans-Jörg Merk)
October 27, 2021, 2:25pm
5
No, we do not recommend using OpenJDK, as there are known issues. Pleas try with Zulu 11.
chris
(Chris Jackson)
October 27, 2021, 7:01pm
6
Yes, use the log file viewer -:
Looking at this I can see some delivery failures from the dongle which likely indicates there is a poor connection to the device -:
This shows the first command sent to the device fails - the coordinator was unable to deliver it. The binding then retries this, and it is successful, but we then also receive a number of responses. Again this indicates that there is likely a communications issue between the coordinator and the device.
smitopher
(Christopher Smith)
October 27, 2021, 8:07pm
7
Thank you
I’m going to try to move the dongle closer to see if that makes any difference. There a a great number of routers (Leviton dimmers) between the current dongle position and the door. I wonder why there is a comm problem?
smitopher
(Christopher Smith)
December 2, 2021, 3:14pm
8
@chris
I want to validate what I see in the event.log and the openhab.log before I go running off to Yale to complain about their terrible Zigbee implementation.
I started OH and waited until all zigbee things were online
From OH, I locked and unlocked the door lock
I then manually locked and unlocked the door lock.
I then, using the lock keypad, I locked and unlocked the doorlock
I then stopped OH
All I see in the events and OH logs are the actions I took using OH, no status changes or events for actions I took directly on the lock and it’s keypad
Do you agree?
TIA
link to logs
events.log
2021-12-02 14:10:29.596 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:coordinator_ember:cd9edd5897' changed from UNKNOWN to ONLINE
2021-12-02 14:10:29.597 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:coordinator_ember:cd9edd5897 changed to UNKNOWN.
2021-12-02 14:10:37.609 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:0022a30000343fac' changed from UNKNOWN to ONLINE
2021-12-02 14:10:37.610 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:cd9edd5897:0022a30000343fac changed to UNKNOWN.
2021-12-02 14:10:49.125 [INFO ] [openhab.event.InboxAddedEvent ] - Discovery Result with UID 'zigbee:device:cd9edd5897:00158d0007751b9e' has been added.
2021-12-02 14:10:57.042 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:0022a30000360415' changed from UNKNOWN to ONLINE
2021-12-02 14:10:57.043 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:cd9edd5897:0022a30000360415 changed to UNKNOWN.
2021-12-02 14:11:02.903 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:0022a3000034ce6b' changed from UNKNOWN to ONLINE
2021-12-02 14:11:02.903 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:cd9edd5897:0022a3000034ce6b changed to UNKNOWN.
2021-12-02 14:11:03.856 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:0022a30000361157' changed from UNKNOWN to ONLINE
This file has been truncated. show original
openhab.log
2021-12-02 14:10:10.188 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'America/Chicago'.
2021-12-02 14:10:10.212 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '30.455911016723103,-97.78094837442042'.
2021-12-02 14:10:10.214 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'en_US'.
2021-12-02 14:10:15.621 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ClosetDoor.things'
2021-12-02 14:10:17.731 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2021-12-02 14:10:18.491 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'ClosetDoor.things' is either empty or cannot be parsed correctly!
2021-12-02 14:10:19.685 [INFO ] [org.openhab.ui.internal.UIService ] - Started UI on port 8080
2021-12-02 14:10:19.848 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - bundle org.openhab.binding.zigbee:3.2.0.202111290338 (261)[org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService] : BundleComponentActivator : ComponentHolder created.
2021-12-02 14:10:19.866 [DEBUG] [al.ZigBeeDefaultDiscoveryParticipant] - bundle org.openhab.binding.zigbee:3.2.0.202111290338 (261)[org.openhab.binding.zigbee.discovery.internal.ZigBeeDefaultDiscoveryParticipant] : BundleComponentActivator : ComponentHolder created.
2021-12-02 14:10:19.868 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - bundle org.openhab.binding.zigbee:3.2.0.202111290338 (261)[org.openhab.binding.zigbee.handler.ZigBeeIsAliveTracker] : BundleComponentActivator : ComponentHolder created.
This file has been truncated. show original
smitopher
(Christopher Smith)
December 8, 2021, 7:29pm
9
@chris I’m following up
I have a much smaller OH log
Same test
Set Zigbee looging to DEBUG
Lock and unlock Zigbee Yale Assure SL from OH
Lock and unlock manually
Lock and unlock using Yale Assure SL Keypad
Lock and unlock Zigbee Yale Assure SL from OH
Set Zigbee logging to INFO
openhab.log (125.2 KB)
Log viewer
I see my OH commands and state updates, I don’t see much that I understand in-between the OH lock/unlock iteration. Definitely no state updates for operations performed on the lock itself.
Do we need to get lower level trace?
Is this enough for me to complain to Yale?
Yale tech support suggested that my lock is not close enough
This test was performed with the lock and Zigbee hub in the same room.
rpwong
(Russ)
December 8, 2021, 8:45pm
10
This sounds an awful lot like the same behaviour as Yale/Schlage Z-Wave locks. In those cases, you have to use the alarm_raw
channel to get updates from the lock. But I don’t know if the same thing exists with Zigbee.
Yep, that’s correct. Here’s the original solution, from a thread that started with a Yale lock.
In OH3, you can apply the JSONPATH transformation directly to the channel, so that it will only send the information you want to the item.
[image]
I’ve isolated the event and use a simple case statement in a rule to update the lock status.
switch (Door_Lock_Alarm_Raw.state.toString)
{
case "1", case "3", case "5" :
{
Door_Lock.postUpdate(ON)
// logInfo("Rules", "Lock updated to ON (locked…
chris
(Chris Jackson)
December 8, 2021, 9:08pm
11
Zigbee is totally different to ZWave and the same channels do not exist.
1 Like
chris
(Chris Jackson)
December 8, 2021, 9:11pm
12
You can try to reinitialise the device. Possibly the device did not get initialised fully and is not sending reports back to the binding when the device state is updated.
smitopher
(Christopher Smith)
December 8, 2021, 10:09pm
13
==> /var/log/openhab/openhab.log <==
2021-12-08 16:02:59.598 [ERROR] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F0010C7023F: Exception creating channels
java.lang.NullPointerException: null
at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterDoorLock.initializeDevice(ZigBeeConverterDoorLock.java:75) ~[bundleFile:?]
at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.initializeDevice(ZigBeeThingHandler.java:514) ~[bundleFile:?]
at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.doNodeInitialisation(ZigBeeThingHandler.java:377) [bundleFile:?]
at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:227) [bundleFile:?]
at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:1) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:829) [?:?]
==> /var/log/openhab/events.log <==
2021-12-08 16:02:59.600 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:000d6f0010c7023f' changed from UNKNOWN to OFFLINE (HANDLER_INITIALIZING_ERROR)
smitopher
(Christopher Smith)
December 8, 2021, 10:10pm
14
I see this allot in my log
smitopher
(Christopher Smith)
December 8, 2021, 10:15pm
15
Disable then enable thing
==> /var/log/openhab/events.log <==
2021-12-08 16:11:05.505 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:000d6f0010c7023f' changed from OFFLINE (HANDLER_INITIALIZING_ERROR) to UNINITIALIZED
2021-12-08 16:11:05.517 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:000d6f0010c7023f' changed from UNINITIALIZED to UNINITIALIZED (DISABLED)
2021-12-08 16:11:09.470 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:000d6f0010c7023f' changed from UNINITIALIZED (DISABLED) to INITIALIZING
2021-12-08 16:11:09.475 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:000d6f0010c7023f' changed from INITIALIZING to UNKNOWN
2021-12-08 16:11:09.475 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:cd9edd5897:000d6f0010c7023f changed to UNKNOWN.
==> /var/log/openhab/openhab.log <==
2021-12-08 16:11:34.542 [ERROR] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F0010C7023F: Exception creating channels
java.lang.NullPointerException: null
at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterDoorLock.initializeDevice(ZigBeeConverterDoorLock.java:75) ~[bundleFile:?]
at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.initializeDevice(ZigBeeThingHandler.java:514) ~[bundleFile:?]
at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.doNodeInitialisation(ZigBeeThingHandler.java:377) [bundleFile:?]
at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:227) [bundleFile:?]
at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$1.call(ZigBeeThingHandler.java:1) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:829) [?:?]
==> /var/log/openhab/events.log <==
2021-12-08 16:11:34.543 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:cd9edd5897:000d6f0010c7023f' changed from UNKNOWN to OFFLINE (HANDLER_INITIALIZING_ERROR)
chris
(Chris Jackson)
December 9, 2021, 2:32am
16
Please use the latest snapshot and let me know if this helps.
smitopher
(Christopher Smith)
December 9, 2021, 3:43am
17
smitopher@myth-server:~$ openhab-cli info
Version: 3.2.0-SNAPSHOT (#2613)
No difference
chris
(Chris Jackson)
December 9, 2021, 3:49am
18
smitopher:
No difference
This version is too old. You need to use the latest zigbee snapshot - not from yesterday!
smitopher
(Christopher Smith)
December 9, 2021, 3:57am
19
I installed using apt, I’ll try again tomorrow and perhaps it will be in the snapshot repo by then
chris
(Chris Jackson)
December 9, 2021, 3:59am
20
Yes, if you don’t want to install manually, then I think you have to wait for the nightly update. Sorry.