zigbee2mqtt
zigbee2mqtt copied to clipboard
zh:ember:uart:ash: Received ERROR from adapter, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT
What happened?
My ZigBee network just stopped working. And I got this error message: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
EDIT:
It seems that this is the main error message zh:ember:uart:ash: Received ERROR from adapter, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT.
It is also worth mentioning, that when I'm restarting the Home Assistant, then somehow Z2M after reboot causes HA to reboot again, but this time Z2M is not running. I had to switch autostart
of Z2M to false, because in other case I will end in reboot loop.
To fix this all I must do is:
Unplug adapter >
reboot Home Assistant >
Start Zigbee2MQTT (it will fail, ok, there is no adapter plugged in) >
Start Zigbee2MQTT again >
wait some time (2 to 4 s) >
plug in adapter.
From now on everything is working perfectly!
What did you expect to happen?
I expected that everything should work smoothly as always 😁
How to reproduce it (minimal and precise)
I don't know how to reproduce it. It has happend second time.
Zigbee2MQTT version
1.39.1
Adapter firmware version
7.4.3
Adapter
Sonoff ZBDongle-E with ember
Setup
HA on a Raspberry Pi 3 (rpi3-64
)
Debug log
Expand to see
[2024-08-28 09:42:23] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/sensor', payload '{"detection_delay":0,"fading_time":2,"illuminance_lux":233,"last_seen":"2024-08-28T09:42:23+02:00","linkquality":200,"maximum_range":5,"minimum_range":0,"presence":false,"radar_sensitivity":4,"target_distance":0}'
[2024-08-28 09:42:24] error: zh:ember:ezsp: ERROR Transaction failure; status=ERROR_WRONG_DIRECTION. Last Frame: [FRAME: ID=52:"SEND_UNICAST" Seq=135 Len=26].
[2024-08-28 09:42:24] error: zh:ember:ezsp: ERROR Transaction failure; status=ERROR_WRONG_DIRECTION. Last Frame: [FRAME: ID=52:"SEND_UNICAST" Seq=135 Len=26].
[2024-08-28 09:42:24] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/sensor', payload '{"detection_delay":0,"fading_time":2,"illuminance_lux":233,"last_seen":"2024-08-28T09:42:24+02:00","linkquality":196,"maximum_range":5,"minimum_range":0,"presence":false,"radar_sensitivity":4,"target_distance":0}'
[2024-08-28 09:42:51] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/sensor', payload '{"detection_delay":0,"fading_time":2,"illuminance_lux":233,"last_seen":"2024-08-28T09:42:51+02:00","linkquality":200,"maximum_range":5,"minimum_range":0,"presence":false,"radar_sensitivity":4,"target_distance":0}'
[2024-08-28 09:42:53] error: zh:ember:ezsp: ERROR Transaction failure; status=ASH_ERROR_TIMEOUTS. Last Frame: [FRAME: ID=52:"SEND_UNICAST" Seq=139 Len=7].
[2024-08-28 09:42:53] error: zh:ember: !!! ADAPTER FATAL ERROR reason=ASH_ERROR_TIMEOUTS. !!!
[2024-08-28 09:42:53] info: zh:ember: Attempting adapter reset...
[2024-08-28 09:42:53] info: zh:ember:uart:ash: ASH COUNTERS since last clear:
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Total frames: RX=2291, TX=2766
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Cancelled : RX=0, TX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: DATA frames : RX=2237, TX=673
[2024-08-28 09:42:53] info: zh:ember:uart:ash: DATA bytes : RX=52490, TX=17515
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Retry frames: RX=41, TX=5
[2024-08-28 09:42:53] info: zh:ember:uart:ash: ACK frames : RX=13, TX=2088
[2024-08-28 09:42:53] info: zh:ember:uart:ash: NAK frames : RX=0, TX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: nRdy frames : RX=0, TX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: CRC errors : RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Comm errors : RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Length < minimum: RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Length > maximum: RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Bad controls : RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Bad lengths : RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Bad ACK numbers : RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Out of buffers : RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Retry dupes : RX=41
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Out of sequence : RX=0
[2024-08-28 09:42:53] info: zh:ember:uart:ash: ACK timeouts : RX=5
[2024-08-28 09:42:53] info: zh:ember:uart:ash: Port closed.
[2024-08-28 09:42:53] info: zh:ember:uart:ash: ======== ASH stopped ========
[2024-08-28 09:42:53] info: zh:ember:ezsp: ======== EZSP stopped ========
[2024-08-28 09:42:53] info: zh:ember: ======== Ember Adapter Stopped ========
[2024-08-28 09:42:54] info: zh:ember: ======== Ember Adapter Starting ========
[2024-08-28 09:42:54] info: zh:ember:ezsp: ======== EZSP starting ========
[2024-08-28 09:42:54] info: zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-08-28 09:42:55] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-08-28 09:42:55] info: zh:ember:uart:ash: Serial port opened
[2024-08-28 09:42:55] info: zh:ember:uart:ash: ======== ASH starting ========
[2024-08-28 09:42:56] info: zh:ember:uart:ash: ======== ASH connected ========
[2024-08-28 09:42:56] info: zh:ember:uart:ash: ======== ASH started ========
[2024-08-28 09:42:56] info: zh:ember:ezsp: ======== EZSP started ========
[2024-08-28 09:42:57] info: zh:ember: Adapter EZSP protocol version (13) lower than Host. Switched.
[2024-08-28 09:42:57] info: zh:ember: Adapter version info: {"ezsp":13,"revision":"7.4.3 [GA]","build":0,"major":7,"minor":4,"patch":3,"special":0,"type":170}
[2024-08-28 09:42:57] info: zh:ember: [STACK STATUS] Network up.
[2024-08-28 09:42:57] info: zh:ember: [INIT TC] Adapter network matches config.
[2024-08-28 09:42:57] info: zh:ember: [CONCENTRATOR] Started source route discovery. 1248ms until next broadcast.
[2024-08-28 09:42:58] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/sensor', payload '{"detection_delay":0,"fading_time":2,"illuminance_lux":233,"last_seen":"2024-08-28T09:42:58+02:00","linkquality":136,"maximum_range":5,"minimum_range":0,"presence":false,"radar_sensitivity":4,"target_distance":0}'
[2024-08-28 09:43:25] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/sensor', payload '{"detection_delay":0,"fading_time":2,"illuminance_lux":233,"last_seen":"2024-08-28T09:43:25+02:00","linkquality":200,"maximum_range":5,"minimum_range":0,"presence":false,"radar_sensitivity":4,"target_distance":0}'
[2024-08-28 09:43:25] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/sensor', payload '{"detection_delay":0,"fading_time":2,"illuminance_lux":233,"last_seen":"2024-08-28T09:43:25+02:00","linkquality":200,"maximum_range":5,"minimum_range":0,"presence":false,"radar_sensitivity":4,"target_distance":0}'
[2024-08-28 09:43:26] error: zh:ember:uart:ash: Received ERROR from adapter, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT.
[2024-08-28 09:43:26] error: zh:ember:uart:ash: ASH disconnected | Adapter status: ASH_NCP_FATAL_ERROR
[2024-08-28 09:43:26] error: zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
[2024-08-28 09:43:27] error: zh:ember: !!! ADAPTER FATAL ERROR reason=HOST_FATAL_ERROR. !!!
[2024-08-28 09:43:27] info: zh:ember: Attempting adapter reset...
[2024-08-28 09:43:27] info: zh:ember:uart:ash: ASH COUNTERS since last clear:
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Total frames: RX=97, TX=109
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Cancelled : RX=0, TX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: DATA frames : RX=77, TX=42
[2024-08-28 09:43:27] info: zh:ember:uart:ash: DATA bytes : RX=1512, TX=569
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Retry frames: RX=17, TX=3
[2024-08-28 09:43:27] info: zh:ember:uart:ash: ACK frames : RX=1, TX=63
[2024-08-28 09:43:27] info: zh:ember:uart:ash: NAK frames : RX=0, TX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: nRdy frames : RX=0, TX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: CRC errors : RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Comm errors : RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Length < minimum: RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Length > maximum: RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Bad controls : RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Bad lengths : RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Bad ACK numbers : RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Out of buffers : RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Retry dupes : RX=17
[2024-08-28 09:43:27] info: zh:ember:uart:ash: Out of sequence : RX=0
[2024-08-28 09:43:27] info: zh:ember:uart:ash: ACK timeouts : RX=3
[2024-08-28 09:43:27] error: zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
[2024-08-28 09:43:29] error: zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: ASH_NCP_FATAL_ERROR
[2024-08-28 09:43:29] error: zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: ASH_NCP_FATAL_ERROR
[2024-08-28 09:43:33] info: zh:ember:uart:ash: Port closed.
[2024-08-28 09:43:35] info: zh:ember:uart:ash: ======== ASH stopped ========
[2024-08-28 09:43:36] info: zh:ember:ezsp: ======== EZSP stopped ========
[2024-08-28 09:43:36] info: zh:ember: ======== Ember Adapter Stopped ========
[2024-08-28 09:43:37] error: zh:ember:ezsp: ERROR Transaction failure; status=ASH_ERROR_TIMEOUTS. Last Frame: [FRAME: ID=0:"VERSION" Seq=0 Len=0].
[2024-08-28 09:43:37] error: zh:ember: !!! ADAPTER FATAL ERROR reason=ASH_ERROR_TIMEOUTS. !!!
[2024-08-28 09:43:37] info: zh:ember: Attempting adapter reset...
[2024-08-28 09:43:37] info: zh:ember:uart:ash: ASH COUNTERS since last clear:
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Total frames: RX=0, TX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Cancelled : RX=0, TX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: DATA frames : RX=0, TX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: DATA bytes : RX=0, TX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Retry frames: RX=0, TX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: ACK frames : RX=0, TX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: NAK frames : RX=0, TX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: nRdy frames : RX=0, TX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: CRC errors : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Comm errors : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Length < minimum: RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Length > maximum: RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Bad controls : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Bad lengths : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Bad ACK numbers : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Out of buffers : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Retry dupes : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: Out of sequence : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: ACK timeouts : RX=0
[2024-08-28 09:43:37] info: zh:ember:uart:ash: ======== ASH stopped ========
[2024-08-28 09:43:37] info: zh:ember:ezsp: ======== EZSP stopped ========
[2024-08-28 09:43:37] info: zh:ember: ======== Ember Adapter Stopped ========
[2024-08-28 09:43:37] info: zh:ember: ======== Ember Adapter Starting ========
[2024-08-28 09:43:37] info: zh:ember:ezsp: ======== EZSP starting ========
[2024-08-28 09:43:37] info: zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-08-28 09:43:38] info: zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-08-28 09:43:38] info: zh:ember:uart:ash: Serial port opened
[2024-08-28 09:43:38] info: zh:ember:uart:ash: ======== ASH starting ========
[2024-08-28 09:43:38] info: zh:ember: ======== Ember Adapter Starting ========
[2024-08-28 09:43:38] info: zh:ember:ezsp: ======== EZSP starting ========
[2024-08-28 09:43:38] info: zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-08-28 09:43:38] info: zh:ember:uart:ash: ======== ASH starting ========
[2024-08-28 09:43:39] info: zh:ember:uart:ash: ======== ASH connected ========
[2024-08-28 09:43:40] info: zh:ember:uart:ash: ======== ASH started ========
[2024-08-28 09:43:40] info: zh:ember:ezsp: ======== EZSP started ========
[2024-08-28 09:43:40] info: zh:ember:uart:ash: ======== ASH started ========
[2024-08-28 09:43:40] info: zh:ember:ezsp: ======== EZSP started ========
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] info: zh:ember: Adapter EZSP protocol version (13) lower than Host. Switched.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] info: zh:ember: Adapter EZSP protocol version (13) lower than Host. Switched.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] info: zh:ember: Adapter version info: {"ezsp":13,"revision":"7.4.3 [GA]","build":0,"major":7,"minor":4,"patch":3,"special":0,"type":170}
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] info: zh:ember: Adapter version info: {"ezsp":13,"revision":"7.4.3 [GA]","build":0,"major":7,"minor":4,"patch":3,"special":0,"type":170}
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember:ezsp: Found no buffer in queue but ASH layer sent signal that one was available.
[2024-08-28 09:43:40] error: zh:ember: Failed to reset and init adapter. Error: Failed to register endpoint '1' with status=ZIGBEE_EZSP_ERROR.
[2024-08-28 09:43:40] info: zh:ember:uart:ash: ASH COUNTERS since last clear:
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Total frames: RX=37, TX=75
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Cancelled : RX=0, TX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: DATA frames : RX=36, TX=37
[2024-08-28 09:43:40] info: zh:ember:uart:ash: DATA bytes : RX=246, TX=394
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Retry frames: RX=0, TX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: ACK frames : RX=0, TX=37
[2024-08-28 09:43:40] info: zh:ember:uart:ash: NAK frames : RX=0, TX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: nRdy frames : RX=0, TX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: CRC errors : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Comm errors : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Length < minimum: RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Length > maximum: RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Bad controls : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Bad lengths : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Bad ACK numbers : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Out of buffers : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Retry dupes : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Out of sequence : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: ACK timeouts : RX=0
[2024-08-28 09:43:40] info: zh:ember:uart:ash: Port closed.
[2024-08-28 09:43:40] info: zh:ember:uart:ash: ======== ASH stopped ========
[2024-08-28 09:43:40] info: zh:ember:ezsp: ======== EZSP stopped ========
[2024-08-28 09:43:41] info: zh:ember: ======== Ember Adapter Stopped ========
[2024-08-28 09:43:41] error: z2m: Adapter disconnected, stopping
[2024-08-28 09:43:41] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"offline"}'
[2024-08-28 09:43:41] info: z2m: Disconnecting from MQTT server
[2024-08-28 09:43:41] info: z2m: Stopping zigbee-herdsman...
[2024-08-28 09:43:41] info: z2m: Stopped zigbee-herdsman
[2024-08-28 09:43:41] info: z2m: Stopped Zigbee2MQTT