[SOLVED] Serial Error: Port /dev/ttyUSB1 does not exist / Bitron / Ember Stick on debian 10

Hello,

facts first:

  • Platform information:
    • Hardware: Intel x64 Celeron 2957U / 8GB RAM / 500GB HDD
    • OS: Debian 10 Buster, Kernel 4.19.67-2+deb10u1
    • Java Runtime Environment: Zulu 8
    • openHAB version: 2.4.0
  • Issue of the topic: Stick can’t be initialized

I bought one of the Bitron USB Zigbee controllers:

Device: 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 0138167A
  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)

I installed openHAB 2.4.0 ia apt and followed the guide that is given here closely, including generating the openhab user, changing the ownership and setting the extra jaba options:

EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyUSB1:/dev/ttyS0:/dev/ttyAMC0"

The stick is seen by openHAB but something’s preventing proper initialization:

openhab.log:

2019-10-04 19:46:02.090 [DEBUG] [org.openhab.binding.zigbee          ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=121, service.bundleid=230, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService, component.id=12} - org.openhab.binding.zigbee
2019-10-04 19:46:02.141 [DEBUG] [org.openhab.binding.zigbee          ] - BundleEvent STARTING - org.openhab.binding.zigbee
2019-10-04 19:46:02.143 [DEBUG] [org.openhab.binding.zigbee          ] - BundleEvent STARTED - org.openhab.binding.zigbee
2019-10-04 19:46:02.163 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBeeDiscoveryService
2019-10-04 19:46:02.188 [DEBUG] [org.openhab.binding.zigbee          ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory}={service.id=122, service.bundleid=230, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory, component.id=13} - org.openhab.binding.zigbee
2019-10-04 19:46:02.311 [DEBUG] [org.openhab.binding.zigbee          ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=123, service.bundleid=230, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.ZigBeeHandlerFactory, component.id=14} - org.openhab.binding.zigbee
2019-10-04 19:46:02.364 [DEBUG] [org.openhab.binding.zigbee          ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryParticipant}={service.id=124, service.bundleid=230, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.internal.ZigBeeDefaultDiscoveryParticipant, component.id=15} - org.openhab.binding.zigbee
2019-10-04 19:46:02.411 [DEBUG] [org.openhab.binding.zigbee          ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.converter.ZigBeeChannelConverterProvider}={service.id=125, service.bundleid=230, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeDefaultChannelConverterProvider, component.id=16} - org.openhab.binding.zigbee
2019-10-04 19:46:02.413 [DEBUG] [org.openhab.binding.zigbee          ] - BundleEvent [unknown:512] - org.openhab.binding.zigbee
2019-10-04 19:46:02.418 [DEBUG] [org.openhab.binding.zigbee.cc2531   ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=126, service.bundleid=231, service.scope=bundle, component.name=org.openhab.binding.zigbee.cc2531.internal.CC2531HandlerFactory, component.id=17} - org.openhab.binding.zigbee.cc2531
2019-10-04 19:46:02.424 [DEBUG] [org.openhab.binding.zigbee.cc2531   ] - BundleEvent STARTING - org.openhab.binding.zigbee.cc2531
2019-10-04 19:46:02.426 [DEBUG] [org.openhab.binding.zigbee.cc2531   ] - BundleEvent STARTED - org.openhab.binding.zigbee.cc2531
2019-10-04 19:46:02.430 [DEBUG] [org.openhab.binding.zigbee.cc2531   ] - BundleEvent [unknown:512] - org.openhab.binding.zigbee.cc2531
2019-10-04 19:46:02.452 [DEBUG] [org.openhab.binding.zigbee.ember    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.usbserial.UsbSerialDiscoveryParticipant}={service.id=127, service.bundleid=232, service.scope=bundle, component.name=org.openhab.binding.zigbee.ember.internal.discovery.ZigBeeEmberUsbSerialDiscoveryParticipant, component.id=18} - org.openhab.binding.zigbee.ember
2019-10-04 19:46:02.454 [DEBUG] [org.openhab.binding.zigbee.ember    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=128, service.bundleid=232, service.scope=bundle, component.name=org.openhab.binding.zigbee.ember.internal.EmberHandlerFactory, component.id=19} - org.openhab.binding.zigbee.ember
2019-10-04 19:46:02.456 [DEBUG] [org.openhab.binding.zigbee.ember    ] - BundleEvent STARTING - org.openhab.binding.zigbee.ember
2019-10-04 19:46:02.458 [DEBUG] [org.openhab.binding.zigbee.ember    ] - BundleEvent STARTED - org.openhab.binding.zigbee.ember
2019-10-04 19:46:02.467 [DEBUG] [org.openhab.binding.zigbee.ember    ] - BundleEvent [unknown:512] - org.openhab.binding.zigbee.ember
2019-10-04 19:46:02.474 [DEBUG] [org.openhab.binding.zigbee.telegesis] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=129, service.bundleid=233, service.scope=bundle, component.name=org.openhab.binding.zigbee.telegesis.internal.TelegesisHandlerFactory, component.id=20} - org.openhab.binding.zigbee.telegesis
2019-10-04 19:46:02.490 [DEBUG] [org.openhab.binding.zigbee.telegesis] - BundleEvent STARTING - org.openhab.binding.zigbee.telegesis
2019-10-04 19:46:02.491 [DEBUG] [org.openhab.binding.zigbee.telegesis] - BundleEvent STARTED - org.openhab.binding.zigbee.telegesis
2019-10-04 19:46:02.495 [DEBUG] [org.openhab.binding.zigbee.telegesis] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.usbserial.UsbSerialDiscoveryParticipant}={service.id=130, service.bundleid=233, service.scope=bundle, component.name=org.openhab.binding.zigbee.telegesis.internal.discovery.ZigBeeTelegesisUsbSerialDiscoveryParticipant, component.id=21} - org.openhab.binding.zigbee.telegesis
2019-10-04 19:46:02.498 [DEBUG] [org.openhab.binding.zigbee.telegesis] - BundleEvent [unknown:512] - org.openhab.binding.zigbee.telegesis
2019-10-04 19:46:02.512 [DEBUG] [org.openhab.binding.zigbee.xbee     ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=131, service.bundleid=234, service.scope=bundle, component.name=org.openhab.binding.zigbee.xbee.internal.XBeeHandlerFactory, component.id=22} - org.openhab.binding.zigbee.xbee
2019-10-04 19:46:02.514 [DEBUG] [org.openhab.binding.zigbee.xbee     ] - BundleEvent STARTING - org.openhab.binding.zigbee.xbee
2019-10-04 19:46:02.516 [DEBUG] [org.openhab.binding.zigbee.xbee     ] - BundleEvent STARTED - org.openhab.binding.zigbee.xbee
2019-10-04 19:46:02.529 [DEBUG] [org.openhab.binding.zigbee.xbee     ] - BundleEvent [unknown:512] - org.openhab.binding.zigbee.xbee
2019-10-04 19:46:03.828 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '50.9149184,6.688768'.
2019-10-04 19:46:03.915 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2019-10-04 19:46:04.145 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2019-10-04 19:46:10.574 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2019-10-04 19:46:11.195 [DEBUG] [org.openhab.binding.zigbee.ember    ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=317, service.bundleid=232, service.scope=singleton} - org.openhab.binding.zigbee.ember
2019-10-04 19:46:11.200 [DEBUG] [org.openhab.binding.zigbee.ember    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.firmware.FirmwareUpdateHandler}={service.id=318, service.bundleid=232, service.scope=singleton} - org.openhab.binding.zigbee.ember
2019-10-04 19:46:11.258 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.
2019-10-04 19:46:11.259 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_ember:0138167A].
2019-10-04 19:46:11.260 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel 11
2019-10-04 19:46:11.261 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID 64981
2019-10-04 19:46:11.262 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID C9B387F8281EC5B8
2019-10-04 19:46:11.263 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key 38C530D12072142C51F5926EF4AE967E
2019-10-04 19:46:11.264 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key 5A6967426565416C6C69616E63653039
2019-10-04 19:46:11.265 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_initialise found, initializeNetwork=false
2019-10-04 19:46:11.266 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key String 38C530D12072142C51F5926EF4AE967E
2019-10-04 19:46:11.267 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key final array 38C530D12072142C51F5926EF4AE967E
2019-10-04 19:46:11.268 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key String 5A6967426565416C6C69616E63653039
2019-10-04 19:46:11.269 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key final array 5A6967426565416C6C69616E63653039
2019-10-04 19:46:11.357 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'/dev/ttyUSB1' PAN:fdd5, EPAN:C9B387F8281EC5B8, Channel:11
2019-10-04 19:46:11.362 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
2019-10-04 19:46:11.866 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.0.12:8080
2019-10-04 19:46:11.872 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.0.12:8443
2019-10-04 19:46:12.177 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2019-10-04 19:46:12.193 [DEBUG] [com.zsmartsystems.zigbee            ] - BundleEvent STARTING - com.zsmartsystems.zigbee
2019-10-04 19:46:12.198 [DEBUG] [com.zsmartsystems.zigbee            ] - BundleEvent STARTED - com.zsmartsystems.zigbee
2019-10-04 19:46:12.201 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.cc2531
2019-10-04 19:46:12.209 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.cc2531
2019-10-04 19:46:12.212 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.ember
2019-10-04 19:46:12.224 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.ember
2019-10-04 19:46:12.226 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.telegesis
2019-10-04 19:46:12.229 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.telegesis
2019-10-04 19:46:12.231 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.xbee
2019-10-04 19:46:12.234 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.xbee
2019-10-04 19:46:12.377 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2019-10-04 19:46:12.378 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2019-10-04 19:46:12.408 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280
2019-10-04 19:46:12.414 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher starting
2019-10-04 19:46:12.497 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster IAS_ZONE
2019-10-04 19:46:12.501 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 25
2019-10-04 19:46:12.503 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster OTA_UPGRADE
2019-10-04 19:46:12.519 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Start.
2019-10-04 19:46:12.531 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Done.
2019-10-04 19:46:12.540 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize with protocol ASH2.
2019-10-04 19:46:12.541 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB1] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF.
2019-10-04 19:46:12.558 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to UNINITIALISED
2019-10-04 19:46:12.563 [ERROR] [ding.zigbee.handler.ZigBeeSerialPort] - Serial Error: Port /dev/ttyUSB1 does not exist.
2019-10-04 19:46:12.566 [ERROR] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unable to open Ember serial port
2019-10-04 19:46:12.584 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=UNINITIALISED
2019-10-04 19:46:12.592 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE
2019-10-04 19:46:12.593 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE

events.log:

2019-10-04 19:46:11.249 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0138167A' changed from UNINITIALIZED to INITIALIZING
2019-10-04 19:46:11.415 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0138167A' changed from INITIALIZING to UNKNOWN
2019-10-04 19:46:12.587 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0138167A' changed from UNKNOWN to OFFLINE: Failed to open communications port
2019-10-04 19:46:12.600 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:0138167A' changed from OFFLINE: Failed to open communications port to OFFLINE (COMMUNICATION_ERROR)
2019-10-04 19:53:36.172 [nt.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:coordinator_ember:0138167A changed to UNKNOWN.

From harvesting through quite a few posts here I learnt it could be just an access rights problem which I can’t resolve (yet) on my own - could someone point me into the right direction?

Thanks in advance :wink:

Daniel

Is the user running OpenHAB part of the dialout group?
What is the output of dmesg | grep tty ?

Hello,

thanks for the reply!

[    0.361281] console [tty0] enabled
[   13.218745] usb 2-5: cp210x converter now attached to ttyUSB0
[ 1014.998628] cp210x ttyUSB0: failed set request 0x7 status: -32
[ 1019.808086] cp210x ttyUSB0: failed set request 0x7 status: -32
[ 1019.815102] cp210x ttyUSB0: failed set request 0x7 status: -32
[ 1019.854591] cp210x ttyUSB0: failed set request 0x7 status: -32
[ 1019.857622] cp210x ttyUSB0: failed set request 0x7 status: -32
[ 1019.993483] cp210x ttyUSB0: failed set request 0x7 status: -32
[ 1020.950586] cp210x ttyUSB0: failed set request 0x7 status: -32
[ 3615.319249] cp210x ttyUSB0: failed set request 0x12 status: -19
[ 3615.319259] cp210x ttyUSB0: failed set request 0x0 status: -19
[ 3615.324357] cp210x ttyUSB0: cp210x converter now disconnected from ttyUSB0
[ 4769.362041] usb 2-5: cp210x converter now attached to ttyUSB1

User openhab was NOT member of group dialout. Now he is :slight_smile:

After a restart of the service, the controller went online - and I was so sure I had added the user to the group … pretty embarassing … :frowning:

Thanks for the help, Bruce, really appreciated. :slight_smile:

Daniel

1 Like