OH3 running as docker container and zigbee usb stick is failing

Add-ons Bindings
1

Hello

I’m starting on a fresh OH3 setup inside a docker container. the zigbee stick I am using is a Bitron Video ZigBee USB Funkstick, which is supported.

The thing itself is configured via config file (adding via UI does not change the result, although it sets some params with other values)

Thing zigbee:coordinator_ember:stick "Zigbee USB Stick" [
    zigbee_port="/dev/ttyUSB0", 
    zigbee_baud=115200, 
    zigbee_flowcontrol=1, 
    zigbee_childtimeout=86400, 
    zigbee_concentrator=1, 
    zigbee_meshupdateperiod=86400, 
    zigbee_panid=35637, 
    zigbee_extendedpanid="118E309DE90CC829", 
    zigbee_networkkey="14 c6 a2 c7 fb e0 c3 19 8e 7c 36 30 dc ad a5 96", 
    zigbee_powermode=1, 
    zigbee_txpower=8
]

the option values are copied from the OH doc for this specific stick. The network keys are also copy&pasted just to be shure they are causing no issue.

The thing itself is not coming online. After setting the appropriate loglevel i can see this in the logs (I hope i caught a complete try/fail cycle)

2020-12-31 16:05:33.670 [INFO ] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee dongle inactivity timer. Reinitializing ZigBee
2020-12-31 16:05:33.674 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager shutdown: networkState=OFFLINE
2020-12-31 16:05:33.676 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set to 0ms
2020-12-31 16:05:33.678 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set less than Max Deferred Write Time
2020-12-31 16:05:33.680 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Max Deferred Write Time set to 0ms
2020-12-31 16:05:33.683 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to SHUTDOWN
2020-12-31 16:05:33.684 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Shutdown
2020-12-31 16:05:33.686 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN
2020-12-31 16:05:33.686 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Shutdown
2020-12-31 16:05:33.691 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false, initialised=false, networkStateUp=false
2020-12-31 16:05:33.693 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false ignored.
2020-12-31 16:05:33.768 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port '/dev/ttyUSB0' closed.
2020-12-31 16:05:33.769 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Shutdown
2020-12-31 16:05:33.771 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Queue shutdown
2020-12-31 16:05:33.773 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Queue shutdown
2020-12-31 16:05:33.774 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.
2020-12-31 16:05:33.782 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'/dev/ttyUSB0' PAN:8b35, EPAN:118E309DE90CC829, Channel:0
2020-12-31 16:05:33.784 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds
2020-12-31 16:05:33.787 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
2020-12-31 16:05:34.792 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2020-12-31 16:05:34.794 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2020-12-31 16:05:34.797 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2]
2020-12-31 16:05:34.800 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=2, interTransactionDelay=4000, maxRetries=0]
2020-12-31 16:05:34.802 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=3, interTransactionDelay=1200, maxRetries=0]
2020-12-31 16:05:34.804 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager initialize: networkState=UNINITIALISED
2020-12-31 16:05:34.806 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING
2020-12-31 16:05:34.809 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Initialize with protocol ASH2.
2020-12-31 16:05:34.809 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
2020-12-31 16:05:34.811 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 115200 baud, flow control FLOWCONTROL_OUT_RTSCTS.
2020-12-31 16:05:34.882 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.
2020-12-31 16:05:44.888 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - No response from ezspVersion command
2020-12-31 16:05:44.890 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Version returned null. ASH/EZSP not initialised.
2020-12-31 16:05:44.892 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE
2020-12-31 16:05:44.894 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE
2020-12-31 16:05:49.904 [INFO ] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee dongle inactivity timer. Reinitializing ZigBee
2020-12-31 16:05:49.906 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager shutdown: networkState=OFFLINE
2020-12-31 16:05:49.909 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set to 0ms
2020-12-31 16:05:49.911 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set less than Max Deferred Write Time
2020-12-31 16:05:49.914 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Max Deferred Write Time set to 0ms
2020-12-31 16:05:49.918 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to SHUTDOWN
2020-12-31 16:05:49.921 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Shutdown
2020-12-31 16:05:49.921 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN
2020-12-31 16:05:49.924 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Shutdown
2020-12-31 16:05:49.928 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false, initialised=false, networkStateUp=false
2020-12-31 16:05:49.930 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false ignored.
2020-12-31 16:05:50.000 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port '/dev/ttyUSB0' closed.
2020-12-31 16:05:50.002 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Shutdown
2020-12-31 16:05:50.004 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Queue shutdown
2020-12-31 16:05:50.006 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Queue shutdown
2020-12-31 16:05:50.009 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.
2020-12-31 16:05:50.013 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'/dev/ttyUSB0' PAN:8b35, EPAN:118E309DE90CC829, Channel:0
2020-12-31 16:05:50.015 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds

The reason for failing seems to be:

2020-12-31 16:05:44.888 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - No response from ezspVersion command
2020-12-31 16:05:44.890 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Version returned null. ASH/EZSP not initialised.

I do not know, if the problem is only the result or the cause :smiley:

Just in case it matters, here my docker-compose snipplet:

[...]
services:
  openhab:
    image: "openhab/openhab:latest"
    container_name: openhab
    restart: always
    ports: 
      - "10080:10080"
    volumes:
      - "/etc/localtime:/etc/localtime:ro"
      - "./openhab-data/conf:/openhab/conf"
      - "./openhab-data/userdata:/openhab/userdata"
      - "./openhab-data/addons:/openhab/addons"
    environment:
      OPENHAB_HTTP_PORT: "10080"
      OPENHAB_HTTPS_PORT: "10443"
      EXTRA_JAVA_OPTS: "-Duser.timezone=Europe/Berlin -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0"
      USER_ID: 1000
      GROUP_ID: 1000
    devices:
      - "/dev/ttyUSB0:/dev/ttyUSB0"

Anyone has an idea, whats wrong here?

EDIT: doing some research:

dmesg of the host is full of

[93048.715083] cp210x ttyUSB0: failed set request 0x7 status: -32

lsusb does not show a usb device:

❯ lsusb
Bus 002 Device 002: ID 174c:55aa ASMedia Technology Inc. Name: ASM1051E SATA 6Gb/s bridge, ASM1053E SATA 6Gb/s bridge, ASM1153 SATA 3Gb/s bridge, ASM1153E SATA 6Gb/s bridge
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 10c4:8b34 Cygnal Integrated Products, Inc. 
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

although there is a /dev/ttyUSB0 device, which “reacts” after pulling the stick out and plugging in again:

[93793.126189] cp210x ttyUSB0: cp210x converter now disconnected from ttyUSB0
[93793.126555] cp210x 1-1.4:1.0: device disconnected
[93853.641140] usb 1-1.4: new full-speed USB device number 4 using xhci_hcd
[93853.777736] usb 1-1.4: New USB device found, idVendor=10c4, idProduct=8b34, bcdDevice= 1.00
[93853.777757] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[93853.777774] usb 1-1.4: Product: BV 2010/10
[93853.777791] usb 1-1.4: Manufacturer: Silicon Labs
[93853.777807] usb 1-1.4: SerialNumber: 01191870
[93853.781346] cp210x 1-1.4:1.0: cp210x converter detected
[93853.789695] usb 1-1.4: cp210x converter now attached to ttyUSB1

wtf ttyUSB1 now ?!

2

another update:

the device is found by lsusb:

❯ lsusb -s  1:3 -v

Bus 001 Device 003: ID 10c4:8b34 Cygnal Integrated Products, Inc. 
Couldn't open device, some information will be missing
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            0
  bDeviceSubClass         0
  bDeviceProtocol         0
  bMaxPacketSize0        64
  idVendor           0x10c4 Cygnal Integrated Products, Inc.
  idProduct          0x8b34
  bcdDevice            1.00
  iManufacturer           1
  iProduct                2
  iSerial                 3
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0020
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0x80
      (Bus Powered)
    MaxPower              100mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass       255 Vendor Specific Class
      bInterfaceSubClass      0
      bInterfaceProtocol      0
      iInterface              2
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x01  EP 1 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x82  EP 2 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0

a little bit strange: the vendorId is not the expected “Silicon Labs” vendor?

3

You can use udev rules to force a fixed name.

4

jep I’ll do so …

concerning my last update:
lsusb as root gives “better” results:

❯ sudo lsusb -s  1:3 -v

Bus 001 Device 003: ID 10c4:8b34 Cygnal Integrated Products, Inc. 
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            0
  bDeviceSubClass         0
  bDeviceProtocol         0
  bMaxPacketSize0        64
  idVendor           0x10c4 Cygnal Integrated Products, Inc.
  idProduct          0x8b34
  bcdDevice            1.00
  iManufacturer           1 Silicon Labs
  iProduct                2 BV 2010/10
  iSerial                 3 01191870
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0020
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0x80
      (Bus Powered)
    MaxPower              100mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass       255 Vendor Specific Class
      bInterfaceSubClass      0
      bInterfaceProtocol      0
      iInterface              2 BV 2010/10
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x01  EP 1 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x82  EP 2 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0
can't get device qualifier: Resource temporarily unavailable
can't get debug descriptor: Resource temporarily unavailable
Device Status:     0x0000
  (Bus Powered)

Still no idea what might be wrong :frowning:
Permissions on the host side should be okay:

the container is running as user with id 1000, this id is given to the container via env and all files are created by this user => the container should be fine itself.
And on the hostside:

❯ id pi
uid=1000(pi) gid=1000(pi) Gruppen=1000(pi),4(adm),20(dialout),24(cdrom),27(sudo),29(audio),44(video),46(plugdev),60(games),100(users),105(input),109(netdev),999(spi),998(i2c),997(gpio),114(docker)
❯ ll /dev/ttyUSB0
crw-rw---- 1 root dialout 188, 0 Dez 31 15:48 /dev/ttyUSB0

so this user should be able to access the device :roll_eyes:

5

aaaaand another update with a little improvement.
I found a thread here where @chris explained, that there are two kinds of this usb sticks around: one with lower bitrate and software control. So I tried these setting and more stuff happens. I’ll attach a complete log here.

imho the conection the stick itself seems to be detected correctly, but still fails to go online (Communication error).

test.log (53.0 KB)

6

I had a quick look at the log - communications with the coordinator is working fine, but it didn’t initialise the network. Try to set the initialise setting to true/1 (I forget exactly what it’s called) to reinitialise the network - hopefully this will resolve the issue. If not, please post the log again.

7

this one did it.

in case some stumbles over this problem:

    zigbee_initialise=true,

must be added to the thing config and changed after successful initialisation to false

thanks @chris

3 Likes