ZigBee device present, visible, but OH cannot open/see it

Hi Folks,

on a Fedora-35 system with OH v3.2.0 installed from the Fedora repo, I am trying to get OH to use a POPP “ZB-Stick”. When I plug it in, I immediately see a new /dev/ttyUSB0 device. lsusb shows me this:

Bus 001 Device 012: ID 1a86:7523 QinHeng Electronics CH340 serial converter

I am following the instructions provided by POPP for using their ZB-Stick with OH, which are here:

I installed the “openHAB ZigBee Binding”, then went to “things”, clicked on the “plus” button, and chose the “ZigBee Binding”. At this point I saw:

I chose the “Ember Coordinator”, and configured:

Port: /dev/ttyUSB0
Flow control: None
Baud Rate: 115200

and left the rest at their defaults. Then I started OH and observed that the Ember Coordinator oscillates between the “ERROR: COMM” and “UNKNOWN” states.
Looking in /var/log/openhab/openhab.log I see the error message:
[DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - No communication ports found, cannot connect to [/dev/ttyUSB0]
(see below for longer excerpt).

I have set SELinux to Permissive mode to rule that out. The OH process is running as the “openhab” user, and /dev/ttyUSB0 is owned by the “dialout” group, of which the “openhab” user is a member. Nevertheless I set the perms on /dev/ttyUSB0 to 666. These things did not help.

Using the Aeotec firmware utility I can “probe” the device and get what seems to be a reasonable answer:

$ python3 Elelabs_EzspFwUtility.py probe -p /dev/ttyUSB0
2022/05/19 15:23:25 Elelabs_EzspFwUtility:   Elelabs Zigbee adapter detected:
2022/05/19 15:23:25 Elelabs_EzspFwUtility:   Adapter: ELU013
2022/05/19 15:23:25 Elelabs_EzspFwUtility:   Firmware: 6.10.0-169
2022/05/19 15:23:25 Elelabs_EzspFwUtility:   EZSP v8

So it seems to be working properly.

I guess I’m doing something wrong… but what?
/treefrob

Larger excerpt from /var/log/openhab/openhab.log:

2022-05-19 16:07:41.513 [INFO ] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee dongle inactivity timer. Reinitializing ZigBee
2022-05-19 16:07:41.513 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager shutdown: networkState=OFFLINE
2022-05-19 16:07:41.513 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set to 0ms
2022-05-19 16:07:41.513 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set less than Max Deferred Write Time
2022-05-19 16:07:41.513 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Max Deferred Write Time set to 0ms
2022-05-19 16:07:41.514 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to SHUTDOWN
2022-05-19 16:07:41.514 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Shutdown
2022-05-19 16:07:41.514 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN
2022-05-19 16:07:41.514 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Shutdown
2022-05-19 16:07:41.514 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Shutdown frameHandler is null
2022-05-19 16:07:41.514 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Shutdown
2022-05-19 16:07:41.514 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Queue shutdown
2022-05-19 16:07:41.514 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Queue shutdown
2022-05-19 16:07:41.514 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.
2022-05-19 16:07:41.515 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:‘/dev/ttyUSB0’ PAN:d8cf, EPAN:BFF5B16EEC444044, Channel:11
2022-05-19 16:07:41.515 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds
2022-05-19 16:07:41.515 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
2022-05-19 16:07:42.515 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2022-05-19 16:07:42.516 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2022-05-19 16:07:42.516 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2]
2022-05-19 16:07:42.516 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=2, interTransactionDelay=4000, maxRetries=0]
2022-05-19 16:07:42.517 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=3, interTransactionDelay=1200, maxRetries=0]
2022-05-19 16:07:42.517 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager initialize: networkState=UNINITIALISED
2022-05-19 16:07:42.517 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING
2022-05-19 16:07:42.518 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Initialize with protocol ASH2.
2022-05-19 16:07:42.518 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
2022-05-19 16:07:42.518 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 115200 baud, flow control FLOWCONTROL_OUT_NONE.
2022-05-19 16:07:42.521 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - No communication ports found, cannot connect to [/dev/ttyUSB0]
2022-05-19 16:07:42.521 [ERROR] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Unable to open serial port
2022-05-19 16:07:42.521 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE
2022-05-19 16:07:42.521 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE

Hi,
I have the same ZB-Stick but set “Flow control: Hardware (CTS/RTS”.
It works for me.

Hi Magnus,

thanks for your response.

I should have mentioned that I also tried hardware flow-control but the error was the same.

-Robert

ok, I did what I should have done before, which was trace the openhab process. I did this and found the problem immediately:
openat(AT_FDCWD, "/var/lock/LCK..ttyUSB0", O_WRONLY|O_CREAT|O_EXCL, 0666) = -1 EACCES (Permission denied)

I added an entry to /usr/lib/tmpfiles.d/legacy.conf to set the group of /var/run to “lock” and the perms to 0775 and the Ember Coordinator immediately went online.

-robert

I have got the same problem, and would like to try your solution - but I am very new to linux. Can I ask you to please copy the exact entry added to /usr/lib/tmpfiles.d/legacy.conf?

Hi Knut,

I did not add, but rather changed a line.

OLD> d /run/lock 0755 root root -
NEW> d /run/lock 0775 root lock -

This causes the /run/lock directory to get the group “lock” and perms 0775, which means r/w/x for the group “lock”.

-robert