Issues with Sonoff dongle crashing and even disappearing?

[aquila]

My Sonoff dongle (ITEAD_SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2) crashes after a couple of days, with read errors. The docker container stops, and then it even disappears as there is no /dev/ttyACM0 anymore. It also disappears from /dev/serial/by-id/ while another device on the same Pi4 keeps working.

Is my dongle just broken because of the /dev/ttyACM0 disappearance or should I try something else?

This seems to be a typical crash sequence:

[2024-10-24 13:18:05] debug: zh:ezsp:ezsp: Time to watchdog ... 0
[2024-10-24 13:18:05] debug: zh:ezsp:ezsp: ==> nop: undefined
[2024-10-24 13:18:05] debug: zh:ezsp:ezsp: ==> {"cls":"nop","id":5,"isRequest":true}
[2024-10-24 13:18:05] debug: zh:ezsp:uart: --> DATA (4,7,0): 6400010500
[2024-10-24 13:18:05] debug: zh:ezsp:uart: --> [472621a9512ab3217e]
[2024-10-24 13:18:05] debug: zh:ezsp:uart: -?- waiting (5)
[2024-10-24 13:18:05] debug: zh:ezsp:uart: <-- [7526a1a9512acad57e]
[2024-10-24 13:18:05] debug: zh:ezsp:uart: <-- DATA (7,5,0): 7526a1a9512acad57e
[2024-10-24 13:18:05] debug: zh:ezsp:uart: --> ACK (0)
[2024-10-24 13:18:05] debug: zh:ezsp:uart: --> [8070787e]
[2024-10-24 13:18:05] debug: zh:ezsp:uart: <-- ACK (5): 7526a1a9512acad57e
[2024-10-24 13:18:05] debug: zh:ezsp:ezsp: <== Frame: 6480010500
[2024-10-24 13:18:05] debug: zh:ezsp:ezsp: <== 0x5: {"cls":"nop","id":5,"isRequest":false}
[2024-10-24 13:18:05] debug: zh:ezsp:uart: -+- waiting (5) success
[2024-10-24 13:18:15] debug: zh:ezsp:ezsp: Time to watchdog ... 0
[2024-10-24 13:18:15] debug: zh:ezsp:ezsp: ==> nop: undefined
[2024-10-24 13:18:15] debug: zh:ezsp:ezsp: ==> {"cls":"nop","id":5,"isRequest":true}
[2024-10-24 13:18:15] debug: zh:ezsp:uart: --> DATA (5,0,0): 6500010500
[2024-10-24 13:18:15] debug: zh:ezsp:uart: --> [502721a9512acbb57e]
[2024-10-24 13:18:15] debug: zh:ezsp:uart: -?- waiting (6)
[2024-10-24 13:18:15] debug: zh:ezsp:uart: <-- [0627a1a9512aebf87e]
[2024-10-24 13:18:15] debug: zh:ezsp:uart: <-- DATA (0,6,0): 0627a1a9512aebf87e
[2024-10-24 13:18:15] debug: zh:ezsp:uart: --> ACK (1)
[2024-10-24 13:18:15] debug: zh:ezsp:uart: --> [8160597e]
[2024-10-24 13:18:15] debug: zh:ezsp:uart: <-- ACK (6): 0627a1a9512aebf87e
[2024-10-24 13:18:15] debug: zh:ezsp:ezsp: <== Frame: 6580010500
[2024-10-24 13:18:15] debug: zh:ezsp:ezsp: <== 0x5: {"cls":"nop","id":5,"isRequest":false}
[2024-10-24 13:18:15] debug: zh:ezsp:uart: -+- waiting (6) success
[2024-10-24 13:18:25] debug: zh:ezsp:ezsp: Time to watchdog ... 0
[2024-10-24 13:18:25] debug: zh:ezsp:ezsp: ==> nop: undefined
[2024-10-24 13:18:25] debug: zh:ezsp:ezsp: ==> {"cls":"nop","id":5,"isRequest":true}
[2024-10-24 13:18:25] debug: zh:ezsp:uart: --> DATA (6,1,0): 6600010500
[2024-10-24 13:18:25] debug: zh:ezsp:uart: --> [612421a9512a4f4b7e]
[2024-10-24 13:18:25] debug: zh:ezsp:uart: -?- waiting (7)
[2024-10-24 13:18:29] error: zh:ezsp:uart: --> Error: Error: {"sequence":7} after 4000ms
[2024-10-24 13:18:29] error: zh:ezsp:uart: -!- break waiting (7)
[2024-10-24 13:18:29] error: zh:ezsp:uart: Can't send DATA frame (6,1,0): 6600010500
[2024-10-24 13:18:29] debug: zh:ezsp:uart: ->> DATA (6,1,1): 6600010500
[2024-10-24 13:18:29] debug: zh:ezsp:uart: --> [692421a9512a42097e]
[2024-10-24 13:18:29] debug: zh:ezsp:uart: -?- rewaiting (7)
[2024-10-24 13:18:33] error: zh:ezsp:uart: --> Error: Error: {"sequence":7} after 4000ms
[2024-10-24 13:18:33] error: zh:ezsp:uart: -!- break rewaiting (7)
[2024-10-24 13:18:33] error: zh:ezsp:uart: Can't resend DATA frame (6,1,1): 6600010500
[2024-10-24 13:18:33] debug: zh:ezsp:ezsp: onSerialReset()
[2024-10-24 13:18:33] debug: zh:ezsp:driv: onEzspReset()
[2024-10-24 13:18:33] debug: zh:ezsp:driv: Reset connection.
[2024-10-24 13:18:33] debug: zh:ezsp:driv: Stopping driver
[2024-10-24 13:18:33] debug: zh:ezsp:ezsp: Closing Ezsp
[2024-10-24 13:18:33] debug: zh:ezsp:uart: Closing UART
[2024-10-24 13:18:33] error: zh:ezsp:ezsp: Watchdog heartbeat timeout Error: Failure send nop:{"type":"Buffer","data":[102,0,1,5,0]}
[2024-10-24 13:18:33] debug: zh:ezsp:uart: Port closed. Error? null
[2024-10-24 13:18:33] debug: zh:ezsp:ezsp: onSerialClose()
[2024-10-24 13:18:34] debug: zh:ezsp:driv: Startup again.
[2024-10-24 13:18:34] debug: zh:ezsp:uart: RTS/CTS config is off, enabling software flow control.
[2024-10-24 13:18:34] debug: zh:ezsp:uart: Opening SerialPort with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true}
[2024-10-24 13:18:34] error: zh:ezsp:ezsp: Connection attempt 1 error: Error: Error: I/O error, cannot open /dev/ttyACM0
[2024-10-24 13:18:39] debug: zh:ezsp:ezsp: Next attempt 2
[2024-10-24 13:18:39] debug: zh:ezsp:uart: RTS/CTS config is off, enabling software flow control.
[2024-10-24 13:18:39] debug: zh:ezsp:uart: Opening SerialPort with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true}
[2024-10-24 13:18:39] error: zh:ezsp:ezsp: Connection attempt 2 error: Error: Error: I/O error, cannot open /dev/ttyACM0
[2024-10-24 13:18:49] debug: zh:ezsp:ezsp: Next attempt 3
[2024-10-24 13:18:49] debug: zh:ezsp:uart: RTS/CTS config is off, enabling software flow control.
[2024-10-24 13:18:49] debug: zh:ezsp:uart: Opening SerialPort with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true}
[2024-10-24 13:18:49] debug: zh:ezsp:uart: Serialport opened
[2024-10-24 13:18:49] debug: zh:ezsp:uart: Uart reseting
[2024-10-24 13:18:49] debug: zh:ezsp:uart: --> Write reset
[2024-10-24 13:18:49] debug: zh:ezsp:uart: --> [1ac038bc7e]
[2024-10-24 13:18:49] debug: zh:ezsp:uart: -?- waiting reset
[2024-10-24 13:18:59] error: zh:ezsp:uart: --> Error: Error: {"sequence":-1} after 10000ms
[2024-10-24 13:18:59] error: zh:ezsp:ezsp: Connection attempt 3 error: Error: Failure to connect
[2024-10-24 13:18:59] debug: zh:ezsp:uart: Port closed. Error? null
[2024-10-24 13:18:59] debug: zh:ezsp:ezsp: onSerialClose()
[2024-10-24 13:18:59] debug: zh:ezsp:driv: onEzspClose()
[2024-10-24 13:18:59] debug: zh:ezsp: onDriverClose()
[2024-10-24 13:18:59] debug: zh:controller: Adapter disconnected
[2024-10-24 13:18:59] debug: zh:ezsp:driv: Stopping driver
[2024-10-24 13:18:59] debug: zh:ezsp:ezsp: Closing Ezsp
[2024-10-24 13:18:59] debug: zh:ezsp:uart: Closing UART
[2024-10-24 13:18:59] debug: zh:ezsp:ezsp: onSerialClose()
[2024-10-24 13:18:59] debug: zh:ezsp:driv: onEzspClose()
[2024-10-24 13:18:59] debug: zh:ezsp: onDriverClose()
[2024-10-24 13:18:59] error: z2m: Adapter disconnected, stopping
[2024-10-24 13:18:59] debug: z2m: Saving state to file /app/data/state.json
[2024-10-24 13:18:59] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"offline"}'
[2024-10-24 13:18:59] info: z2m: Disconnecting from MQTT server
[2024-10-24 13:18:59] info: z2m: Stopping zigbee-herdsman...
[2024-10-24 13:18:59] debug: zh:controller:database: Writing database to '/app/data/database.db'
[2024-10-24 13:18:59] info: z2m: Stopped zigbee-herdsman
[2024-10-24 13:18:59] info: z2m: Stopped Zigbee2MQTT

[power380]

Hello. I have the same problem with the Sonoff Zb Bridge coordinator, with the Tasmota firmware. It seems to me that the problem appeared in the Zigbee2MQTT 1.40.2-1 version. Unfortunately, I did not immediately notice the problem and deleted the backups of the previous version. I have HomeAssistant Supervised installed and I do not yet understand how to roll back to the previous version of Home Assistant without a backup.

[2024-10-28 12:07:43] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:07:43+03:00","linkquality":156,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:07:59] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":5} after 4000ms
[2024-10-28 12:07:59] error: 	zh:ezsp:uart: -!- break waiting (5)
[2024-10-28 12:07:59] error: 	zh:ezsp:uart: Can't send DATA frame (4,3,0): 7c00010500
[2024-10-28 12:10:41] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:10:41+03:00","linkquality":152,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:12:06] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Термометр1', payload '{"battery":100,"humidity":46.68,"last_seen":"2024-10-28T12:12:06+03:00","linkquality":164,"power_outage_count":10075,"temperature":24.84,"voltage":3035}'
[2024-10-28 12:13:25] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:13:25+03:00","linkquality":160,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:14:04] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Свет в кухне', payload '{"last_seen":"2024-10-28T12:14:03+03:00","linkquality":72,"state":"OFF"}'
[2024-10-28 12:14:06] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Бра в кухне', payload '{"last_seen":"2024-10-28T12:14:06+03:00","linkquality":76,"state":"OFF"}'
[2024-10-28 12:14:16] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Люстра в кухне', payload '{"last_seen":"2024-10-28T12:14:16+03:00","linkquality":84,"state":"OFF"}'
[2024-10-28 12:14:19] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Свет в прихожей', payload '{"last_seen":"2024-10-28T12:14:19+03:00","linkquality":80,"state":"OFF"}'
[2024-10-28 12:16:06] error: 	zh:ezsp:uart: Error while parsing to NpiFrame 'Error: <-- CRC error: f1b1a9112a15b658944a24ab5593499cd3876f7e609874f2ce9883fd7e1ff70932fe5f6b00e7dbd79b177e|9b17|fa4a'
[2024-10-28 12:16:06] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:16:06+03:00","linkquality":160,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:16:06] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:16:06+03:00","linkquality":156,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:16:06] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:16:06+03:00","linkquality":156,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:16:06] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:16:06+03:00","linkquality":156,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:16:06] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:16:06+03:00","linkquality":152,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:18:56] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:18:56+03:00","linkquality":160,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:18:56] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:18:56+03:00","linkquality":160,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:18:56] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:18:56+03:00","linkquality":160,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:18:56] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:18:56+03:00","linkquality":160,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:18:56] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:18:56+03:00","linkquality":160,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:18:56] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:18:56+03:00","linkquality":160,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:18:56] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Клапан воды', payload '{"indicator_mode":"off/on","last_seen":"2024-10-28T12:18:56+03:00","linkquality":156,"power_on_behavior":"previous","state":"ON"}'
[2024-10-28 12:20:49] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":2} after 4000ms
[2024-10-28 12:20:49] error: 	zh:ezsp:uart: -!- break waiting (2)
[2024-10-28 12:20:49] error: 	zh:ezsp:uart: Can't send DATA frame (1,6,0): d100010500
[2024-10-28 12:20:54] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":2} after 4000ms
[2024-10-28 12:20:54] error: 	zh:ezsp:uart: -!- break rewaiting (2)
[2024-10-28 12:20:54] error: 	zh:ezsp:uart: Can't resend DATA frame (1,6,1): d100010500
[2024-10-28 12:20:54] error: 	zh:ezsp:ezsp: Watchdog heartbeat timeout Error: Failure send nop:{"type":"Buffer","data":[209,0,1,5,0]}
[2024-10-28 12:21:13] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":7} after 4000ms
[2024-10-28 12:21:13] error: 	zh:ezsp:uart: -!- break waiting (7)
[2024-10-28 12:21:13] error: 	zh:ezsp:uart: Can't send DATA frame (6,7,0): 1e00016a0001
[2024-10-28 12:21:32] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":5} after 4000ms
[2024-10-28 12:21:32] error: 	zh:ezsp:uart: -!- break waiting (5)
[2024-10-28 12:21:32] error: 	zh:ezsp:uart: Can't send DATA frame (4,7,0): 2c00010500
[2024-10-28 12:21:36] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":5} after 4000ms
[2024-10-28 12:21:36] error: 	zh:ezsp:uart: -!- break rewaiting (5)
[2024-10-28 12:21:36] error: 	zh:ezsp:uart: Can't resend DATA frame (4,7,1): 2c00010500
[2024-10-28 12:21:36] error: 	zh:ezsp:ezsp: Watchdog heartbeat timeout Error: Failure send nop:{"type":"Buffer","data":[44,0,1,5,0]}
[2024-10-28 12:21:47] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":2} after 4000ms
[2024-10-28 12:21:47] error: 	zh:ezsp:uart: -!- break waiting (2)
[2024-10-28 12:21:47] error: 	zh:ezsp:uart: Can't send DATA frame (1,1,0): 010001000008
[2024-10-28 12:21:52] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":2} after 4000ms
[2024-10-28 12:21:52] error: 	zh:ezsp:uart: -!- break rewaiting (2)
[2024-10-28 12:21:52] error: 	zh:ezsp:uart: Can't resend DATA frame (1,1,1): 010001000008
[2024-10-28 12:22:00] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":1} after 4000ms
[2024-10-28 12:22:00] error: 	zh:ezsp:uart: -!- break waiting (1)
[2024-10-28 12:22:00] error: 	zh:ezsp:uart: Can't send DATA frame (0,0,0): 00000004
[2024-10-28 12:22:05] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":1} after 4000ms
[2024-10-28 12:22:05] error: 	zh:ezsp:uart: -!- break rewaiting (1)
[2024-10-28 12:22:05] error: 	zh:ezsp:uart: Can't resend DATA frame (0,0,1): 00000004
[2024-10-28 12:22:19] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":0} after 4000ms
[2024-10-28 12:22:19] error: 	zh:ezsp:uart: -!- break waiting (0)
[2024-10-28 12:22:19] error: 	zh:ezsp:uart: Can't send DATA frame (7,7,0): 070001530012001e
[2024-10-28 12:22:32] error: 	zh:ezsp:uart: --> Error: Error: {"sequence":2} after 4000ms
[2024-10-28 12:22:32] error: 	zh:ezsp:uart: -!- break waiting (2)
[2024-10-28 12:22:32] error: 	zh:ezsp:uart: Can't send DATA frame (1,3,0): 210001520006
[2024-10-28 12:22:32] error: 	zh:ezsp:uart: --> Error: Error: Recv NAK frame
[2024-10-28 12:22:32] error: 	zh:ezsp:uart: -!- break rewaiting (2)
[2024-10-28 12:22:32] error: 	zh:ezsp:uart: Can't resend DATA frame (1,3,1): 210001520006
[2024-10-28 12:24:05] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Свет в кухне', payload '{"last_seen":"2024-10-28T12:24:05+03:00","linkquality":76,"state":"OFF"}'
[2024-10-28 12:24:07] info: 	z2m:mqtt: MQTT publish: topic 'mqtt/Бра в кухне', payload '{"last_seen":"2024-10-28T12:24:07+03:00","linkquality":68,"state":"OFF"}'

[aquila]

I have the issue with version 1.40.1 (commit #403d3c0).

[power380]

I think I found the reason for the errors. It was all about a dead battery in one of the wireless sensors. Apparently, he transmitted incorrect data, which hung up the system. After replacing the battery, the errors are gone. By the way, I noticed that the blue LED on the gateway starts to glow (pale) when ZigBee2mqtt finally freezes.