[SOLVED] Fail to start Zigbee transport layer

Kim_Andersen · February 25, 2022, 12:57am

I have this very odd problem.

I installed my Zigbee dongle a coupple of hours ago on my OH3.2 (running openhabian on Rpi4). Its a EM357s-USB-LR dongle.

When I first installed it, it worked just fine. When online, and for some reason it found 3 unknown devices, which I´m not aware of. I couldnt really figure why these devices were unknown, so insted I tried to add another device which I know what is… When scanning it didnt find the device. Then I tried yet another device. But still it didn´t find anything.

I then thought, that maybe there was something with the cordinator and the devices, which used to run OH 2.5 some months ago. So I guess I would try to reinitialise the controller.
That seem like a very bad idea, cause after I Reinitialsed the controller, it will no longer turn to online. I get the:
Fail to start Zigbee transport layer

I have tried everything to bring it back online. Even removed everything and reinstalled the binding. But I end up with the same. Cleared cache etc, rebooted and even powered everything down. Nothing seems to get me past the faliure.

This is a debug logging of whats happning:

2022-02-25 01:24:40.672 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2022-02-25 01:24:40.673 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2022-02-25 01:24:40.677 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 115200 baud, flow control FLOWCONTROL_OUT_RTSCTS.
2022-02-25 01:24:40.677 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
2022-02-25 01:24:40.744 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.
2022-02-25 01:24:45.288 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Mesh Update Period 86400
2022-02-25 01:24:45.299 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee Initialise: Previous device configuration was: channel=CHANNEL_11, PanID=20498, EPanId=688E4409B074A562
2022-02-25 01:24:45.300 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key initialise 5A6967426565416C6C69616E63653039
2022-02-25 01:24:45.301 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key initialise 1C842590C02AE89785E43F401D40C8EF
2022-02-25 01:24:45.302 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_trustcentremode=TC_JOIN_SECURE
2022-02-25 01:24:46.370 [WARN ] [.internal.EmberNetworkInitialisation] - Energy scan found all channels violate CCA threshold!
2022-02-25 01:24:46.373 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE
==> /var/log/openhab/events.log <==
2022-02-25 01:24:46.376 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:coordinator_ember:6a59deb05b' changed from UNKNOWN to OFFLINE: Failed to startup ZigBee transport layer
2022-02-25 01:24:46.378 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:coordinator_ember:6a59deb05b' changed from OFFLINE: Failed to startup ZigBee transport layer to OFFLINE (COMMUNICATION_ERROR)
==> /var/log/openhab/openhab.log <==
2022-02-25 01:24:51.376 [INFO ] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee dongle inactivity timer. Reinitializing ZigBee
2022-02-25 01:24:51.381 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN
2022-02-25 01:24:51.463 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port '/dev/ttyUSB0' closed.
2022-02-25 01:24:51.465 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.
2022-02-25 01:24:51.467 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'/dev/ttyUSB0' PAN:fa01, EPAN:CC6F548A07897CBB, Channel:11
2022-02-25 01:24:51.468 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds
2022-02-25 01:24:51.471 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
==> /var/log/openhab/events.log <==
2022-02-25 01:24:51.473 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:coordinator_ember:6a59deb05b' changed from OFFLINE (COMMUNICATION_ERROR) to UNKNOWN
==> /var/log/openhab/openhab.log <==
2022-02-25 01:24:52.473 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2022-02-25 01:24:52.475 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2022-02-25 01:24:52.478 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 115200 baud, flow control FLOWCONTROL_OUT_RTSCTS.
2022-02-25 01:24:52.478 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
2022-02-25 01:24:52.551 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.
2022-02-25 01:24:57.262 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Mesh Update Period 86400
2022-02-25 01:24:57.275 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee Initialise: Previous device configuration was: channel=CHANNEL_11, PanID=20498, EPanId=688E4409B074A562
2022-02-25 01:24:57.276 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key initialise 5A6967426565416C6C69616E63653039
2022-02-25 01:24:57.277 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key initialise 1C842590C02AE89785E43F401D40C8EF
2022-02-25 01:24:57.278 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_trustcentremode=TC_JOIN_SECURE
2022-02-25 01:24:58.326 [WARN ] [.internal.EmberNetworkInitialisation] - Energy scan found all channels violate CCA threshold!
2022-02-25 01:24:58.329 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE
==> /var/log/openhab/events.log <==
2022-02-25 01:24:58.330 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:coordinator_ember:6a59deb05b' changed from UNKNOWN to OFFLINE: Failed to startup ZigBee transport layer
2022-02-25 01:24:58.333 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:coordinator_ember:6a59deb05b' changed from OFFLINE: Failed to startup ZigBee transport layer to OFFLINE (COMMUNICATION_ERROR)

I really wonder how come this happed after I activated the Reinitialise controller. But it looks like something got stuck somewhere. And I have no idea how to get it to work again?

Maybe @chris ?

chris · February 25, 2022, 1:41am

The problem seems to be noise - you probably need to put a USB cable between the RPi and the dongle as it’s creating a lot of RF noise where it is and that doesn’t allow the dongle to work.

Kim_Andersen · February 25, 2022, 8:55am

Seems to be the reason. I Moved it away from the rpi, and after yet another reinitialise, it works just fine…

Thanks alot Chris…

chris · February 25, 2022, 8:08pm

Mainly for others who read this - the logs shows the following error -:

Energy scan found all channels violate CCA threshold!

This means that all channels are too noisy and the coordinator will not transmit at all. When the coordinator sends data, it first checks that no other devices are sending, and to do this it checks the signal level and compares it to this “CCA threshold” - it won’t transmit on the channel until it is clear.

chris · February 25, 2022, 8:08pm

Mainly for others who read this - the logs shows the following error -:

Energy scan found all channels violate CCA threshold!

This means that all channels are too noisy and the coordinator will not transmit at all. When the coordinator sends data, it first checks that no other devices are sending, and to do this it checks the signal level and compares it to this “CCA threshold” - it won’t transmit on the channel until it is clear.