OH3 zigbee binding not working with RFC2217 port

Tags: #<Tag:0x00007fc8f70d5530> #<Tag:0x00007fc8f70d5440> #<Tag:0x00007fc8f70d5300>

I’m testing OH3 in a docker container in a VM on my server and while the ZWave binding works great connecting to rfc2217://192.168.0.5:3001, the Zigbee binding configured for rfc2217://192.168.0.5:3002 errors out and gives me “No communication ports found, cannot connect to [rfc2217://192.168.0.5:3002]” in the debug log (full log below). The box at 192.168.0.5 is a raspberry pi with a fresh minimal image and only has ser2net running with this config and I have verified with netstat that both ports 3001 and 3002 are open and listening. I have also tried setting the baud on ser2net and the thing config to 115200 but same issue. I currently have it as 57600 because that’s what seemed to work best with my elelabs usb stick when it was physically connected to my OH2 box. Am I missing something or does the zigbee OH3 binding not work with RFC2217 ports? I would try it with zigbee2mqtt but as far as I can gather that doesn’t work with ember chipset dongles.

ser2net config:

192.168.0.5,3001:telnet:0:/dev/ttyUSB-ACM0:115200 8DATABITS NONE 1STOPBIT remctl
192.168.0.5,3002:telnet:0:/dev/ttyUSB0:57600 8DATABITS NONE 1STOPBIT remctl

netstat:

pi@ser2net:~ $ sudo netstat -tulpn | grep LISTEN
tcp        0      0 192.168.0.5:3001        0.0.0.0:*               LISTEN      3504/ser2net        
tcp        0      0 192.168.0.5:3002        0.0.0.0:*               LISTEN      3504/ser2net        

Debug log:

2021-01-13 15:32:59.995 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager shutdown: networkState=OFFLINE
2021-01-13 15:32:59.996 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set to 0ms
2021-01-13 15:32:59.997 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set less than Max Deferred Write Time
2021-01-13 15:32:59.998 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Max Deferred Write Time set to 0ms
2021-01-13 15:32:59.999 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to SHUTDOWN
2021-01-13 15:33:00.000 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN
2021-01-13 15:33:00.000 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Shutdown
2021-01-13 15:33:00.000 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Shutdown
2021-01-13 15:33:00.001 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Shutdown frameHandler is null
2021-01-13 15:33:00.001 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Shutdown
2021-01-13 15:33:00.004 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Queue shutdown
2021-01-13 15:33:00.004 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Queue shutdown
2021-01-13 15:33:00.005 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network [zigbee:coordinator_ember:40e943dd3b] closed.
2021-01-13 15:33:00.005 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_ember:40e943dd3b].
2021-01-13 15:33:00.005 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel 11
2021-01-13 15:33:00.009 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID XXXX
2021-01-13 15:33:00.012 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID XXXX
2021-01-13 15:33:00.013 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key XXXX
2021-01-13 15:33:00.013 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key XXXX
2021-01-13 15:33:00.013 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_initialise found, initializeNetwork=false
2021-01-13 15:33:00.013 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key String XXXX
2021-01-13 15:33:00.015 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key final array XXXX
2021-01-13 15:33:00.015 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key String XXXX
2021-01-13 15:33:00.015 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key final array XXXX
2021-01-13 15:33:00.016 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.
2021-01-13 15:33:00.016 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'rfc2217://192.168.0.5:3002' PAN:XXXX, XXXX, Channel:11
2021-01-13 15:33:00.038 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds
2021-01-13 15:33:00.040 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
2021-01-13 15:33:01.040 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2021-01-13 15:33:01.041 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2021-01-13 15:33:01.042 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2]
2021-01-13 15:33:01.042 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=2, interTransactionDelay=4000, maxRetries=0]
2021-01-13 15:33:01.042 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=3, interTransactionDelay=1200, maxRetries=0]
2021-01-13 15:33:01.043 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager initialize: networkState=UNINITIALISED
2021-01-13 15:33:01.043 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING
2021-01-13 15:33:01.050 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Initialize with protocol ASH2.
2021-01-13 15:33:01.050 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [rfc2217://192.168.0.5:3002] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF.
2021-01-13 15:33:01.051 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - No communication ports found, cannot connect to [rfc2217://192.168.0.5:3002]
2021-01-13 15:33:01.051 [ERROR] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Unable to open serial port
2021-01-13 15:33:01.051 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE
2021-01-13 15:33:01.052 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
2021-01-13 15:33:01.053 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE

Here’s my Zigbee coordinator thing config as well. I’ve matched everything but the port to match what they were in my previous OH2 config that I had on my old server which worked fine with the dongle directly connected.

UID: zigbee:coordinator_ember:40e943dd3b
label: Ember EM35x Coordinator
thingTypeUID: zigbee:coordinator_ember
configuration:
  zigbee_port: rfc2217://192.168.0.5:3002
  zigbee_initialise: false
  zigbee_channel: 11
  zigbee_concentrator: 0
  zigbee_trustcentremode: TC_JOIN_SECURE
  zigbee_extendedpanid: XXXXXX
  zigbee_flowcontrol: 2
  zigbee_baud: 57600
  zigbee_panid: XXXXXX
  zigbee_powermode: 1
  zigbee_txpower: 0
  zigbee_networksize: 25
  zigbee_linkkey: XXXXXXX
  zigbee_childtimeout: 86400
  zigbee_networkkey: XXXXXX
  zigbee_meshupdateperiod: 86400

Probably will not work until #577 is fixed.

Thanks for the info, I guess i’ll do socat for now then until it gets fixed.