Addon keeps on crashing and restarting

[mbrucher]

Description of the issue

The addon keeps on crashing and restarting. I think it's related to the latest upgrade, or a recent one, as the addon was stable for a long time before this.
For instance:

Starting Zigbee2MQTT without watchdog.
[2024-11-03 16:14:20] error: 	zh:ember:uart:ash: Received ERROR from adapter while connecting, with code=RESET_WATCHDOG.
[2024-11-03 16:15:28] error: 	z2m: Publish 'set' 'state' to '0xa4c138de5c48acae' failed: 'Error: ZCL command 0xa4c138de5c48acae/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '37278'.)'
[2024-11-03 16:17:27] error: 	z2m: Failed to configure '0x282c02bfffebb207', attempt 1 (Error: Bind 0x282c02bfffebb207/1 msTemperatureMeasurement from '0xbc026efffe24c587/1' failed (Delivery failed for '35997'.)
    at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:100:31)
    at EmberAdapter.onMessageSent (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:469:42)
    at Ezsp.emit (node:events:519:28)
    at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:5032:14)
    at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:735:26)
    at Ezsp.onAshFrame (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:395:22)
    at UartAsh.emit (node:events:519:28)
    at Immediate.<anonymous> (/app/node_modules/zigbee-herdsman/src/adapter/ember/uart/ash.ts:1169:45)
    at processImmediate (node:internal/timers:478:21))
[2024-11-03 16:19:40] error: 	z2m: Failed to configure '0x282c02bfffebb3c1', attempt 1 (Error: Bind 0x282c02bfffebb3c1/1 msTemperatureMeasurement from '0xbc026efffe24c587/1' failed (Delivery failed for '7735'.)
    at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:100:31)
    at EmberAdapter.onMessageSent (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:469:42)
    at Ezsp.emit (node:events:519:28)
    at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:5032:14)
    at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:735:26)
    at Ezsp.onAshFrame (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:395:22)
    at UartAsh.emit (node:events:519:28)
    at Immediate.<anonymous> (/app/node_modules/zigbee-herdsman/src/adapter/ember/uart/ash.ts:1169:45)
    at processImmediate (node:internal/timers:478:21))
[2024-11-03 16:21:08] error: 	z2m: Failed to read state of '0xa4c13867d1e82b5b' after reconnect (ZCL command 0xa4c13867d1e82b5b/1 genOnOff.read(["onOff"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '35681'.))
[2024-11-03 16:21:57] error: 	z2m: Failed to read state of '0xa4c13867d1e82b5b' after reconnect (ZCL command 0xa4c13867d1e82b5b/1 genOnOff.read(["onOff"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '35681'.))
[2024-11-03 16:25:13] error: 	z2m: Failed to configure '0x282c02bfffeaaed6', attempt 1 (Error: Bind 0x282c02bfffeaaed6/1 msTemperatureMeasurement from '0xbc026efffe24c587/1' failed (Delivery failed for '49381'.)
    at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:100:31)
    at EmberAdapter.onMessageSent (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:469:42)
    at Ezsp.emit (node:events:519:28)
    at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:5032:14)
    at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:735:26)
    at Ezsp.onAshFrame (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:395:22)
    at UartAsh.emit (node:events:519:28)
    at Immediate.<anonymous> (/app/node_modules/zigbee-herdsman/src/adapter/ember/uart/ash.ts:1169:45)
    at processImmediate (node:internal/timers:478:21))
[2024-11-03 16:25:40] error: 	z2m: Failed to configure '0x282c02bfffebb3c1', attempt 2 (Error: Bind 0x282c02bfffebb3c1/1 msTemperatureMeasurement from '0xbc026efffe24c587/1' failed (Delivery failed for '7735'.)
    at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:100:31)
    at EmberAdapter.onMessageSent (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:469:42)
    at Ezsp.emit (node:events:519:28)
    at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:5032:14)
    at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:735:26)
    at Ezsp.onAshFrame (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:395:22)
    at UartAsh.emit (node:events:519:28)
    at Immediate.<anonymous> (/app/node_modules/zigbee-herdsman/src/adapter/ember/uart/ash.ts:1169:45)
    at processImmediate (node:internal/timers:478:21))
[2024-11-03 16:25:46] error: 	z2m: Failed to read state of '0xa4c13867d1e82b5b' after reconnect (ZCL command 0xa4c13867d1e82b5b/1 genOnOff.read(["onOff"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '35681'.))
[2024-11-03 16:26:18] error: 	zh:ember: Delivery of BROADCAST failed for '65533'.

This seems to be related to ThirdReality thermostats, but they were working properly before, so no reason for them to start failing to be configured?

Addon version

v1.41.0-1

Platform

ore 2024.10.4
Supervisor 2024.10.3
Operating System 13.2
Frontend 20241002.4

Logs of the issue (if applicable)

No response

[qbushome]

i'm not sure it this is related but eventually also in my case Zigbee2MQTT stops and restarts, all within 10 seconds.

`[2024-11-25 08:06:48] error: zh:ember:uart:ash: Port Error: read ECONNRESET

[2024-11-25 08:06:48] error: zh:ember: Adapter fatal error: ERROR_SERIAL_INIT

[2024-11-25 08:06:48] info: zh:ember:uart:ash: ASH COUNTERS since last clear:

[2024-11-25 08:06:48] info: zh:ember:uart:ash: Total frames: RX=163, TX=217

[2024-11-25 08:06:48] info: zh:ember:uart:ash: Cancelled : RX=0, TX=0

[2024-11-25 08:06:48] info: zh:ember:uart:ash: DATA frames : RX=162, TX=53
[2024-11-25 08:06:48] info: zh:ember:uart:ash: DATA bytes : RX=3579, TX=788
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Retry frames: RX=0, TX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: ACK frames : RX=0, TX=163
[2024-11-25 08:06:48] info: zh:ember:uart:ash: NAK frames : RX=0, TX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: nRdy frames : RX=0, TX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: CRC errors : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Comm errors : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Length < minimum: RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Length > maximum: RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Bad controls : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Bad lengths : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Bad ACK numbers : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Out of buffers : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Retry dupes : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: Out of sequence : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: ACK timeouts : RX=0
[2024-11-25 08:06:48] info: zh:ember:uart:ash: ======== ASH stopped ========
[2024-11-25 08:06:48] info: zh:ember:ezsp: ======== EZSP stopped ========
[2024-11-25 08:06:48] info: zh:ember: ======== Ember Adapter Stopped ========
[2024-11-25 08:06:48] error: z2m: Adapter disconnected, stopping
[2024-11-25 08:06:48] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"offline"}'
[2024-11-25 08:06:48] info: z2m: Disconnecting from MQTT server
[2024-11-25 08:06:48] info: z2m: Stopping zigbee-herdsman...
[2024-11-25 08:06:48] info: z2m: Stopped zigbee-herdsman
[2024-11-25 08:06:48] info: z2m: Stopped Zigbee2MQTT
/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264
var er = new ERR_STREAM_WRITE_AFTER_END();
^
Error: write after end
at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12)
at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21)
at DerivedLogger.log (/app/node_modules/winston/lib/winston/logger.js:231:12)
at Logger.log (/app/lib/util/logger.ts:198:25)
at Logger.info (/app/lib/util/logger.ts:211:14)
at UartAsh.onPortClose (/app/node_modules/zigbee-herdsman/src/adapter/ember/uart/ash.ts:547:16)
at Object.onceWrapper (node:events:634:26)
at Socket.emit (node:events:519:28)
at TCP. (node:net:338:12)
[08:06:55] INFO: Preparing to start...
[08:06:55] INFO: Socat not enabled
[08:06:55] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-11-25 08:06:57] info: z2m: Logging to console, file (filename: log.log)
[2024-11-25 08:06:57] info: z2m: Starting Zigbee2MQTT version 1.41.0 (commit #unknown)
[2024-11-25 08:06:57] info: z2m: Starting zigbee-herdsman (2.1.7)
`

Frequency can be seen in screenshot below:
I have multiple temperature sensors. 2 for each room. I calculate the average and create a new sensor. The graph below is this average sensor.
Every time Zigbee2MQTT crashes, the Zigbee sensor reports '0', resulting in an average temperature of approx. half real temperature.

For my Zigbee buttons:
I have triggers in automations based on state change, the automation sees this crash as a button press, and 10 seconds later again.

Using an smlight slzb-06m, PoE powered

[Koenkk]

These looks like connection issues with the dongle, likely cannot be fixed from the Z2M side. Make sure that you don't have any other addons that use USB devices running (I would advise to stop all other addons and see if the issue is still there)

[andreashm]

I don't know if it's exactly the same, but since v1.42 I have trouble with Z2M. It restarts x times a day without further notice. I think it is a software issue, becaue in older versions I didn't see this phenomenon. I can decline a hardware problem, because I changed the USB-Port of the dongle, the USB Cable (I tried 3 different ones) and even the stick itself (Sonoff Dongle-E).

All I can see in the logs:
[22:09:34] INFO: Preparing to start...
[22:09:34] INFO: Socat not enabled
[22:09:35] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[22:10:15] INFO: Preparing to start...
[22:10:15] INFO: Socat not enabled
[22:10:16] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[22:10:43] INFO: Preparing to start...
[22:10:43] INFO: Socat not enabled
[22:10:44] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[22:11:14] INFO: Preparing to start...
[22:11:15] INFO: Socat not enabled
[22:11:15] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-12-16 22:11:58] error: z2m: Failed to read state of 'Esstisch Rechts 3' after reconnect (ZCL command 0x00158d0002cba08f/1 genOnOff.read(["onOff"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '44219'.))
[2024-12-16 22:12:02] warning: z2m: Failed to ping 'Esstisch Rechts 2' (attempt 1/1, ZCL command 0x00158d0002ca4be7/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '19341'.))
[2024-12-16 22:12:12] warning: z2m: Failed to ping 'Küche 4' (attempt 1/1, ZCL command 0x00158d0002ca6f97/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '57380'.))
[2024-12-16 22:12:19] warning: z2m: Failed to ping 'Küche 1' (attempt 1/1, ZCL command 0x00158d0002cabde6/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '26897'.))
[2024-12-16 22:12:42] warning: z2m: Failed to ping 'Spüle Mitte' (attempt 1/1, ZCL command 0x00158d0002ca4e4e/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '22074'.))
[03:09:56] INFO: Preparing to start...
[03:09:57] INFO: Socat not enabled
[03:09:57] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-12-17 03:10:38] warning: z2m: Failed to ping 'Unterschranklicht' (attempt 1/1, ZCL command 0x7cb03eaa0a020cec/3 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '60571'.))
[2024-12-17 03:10:48] warning: z2m: Failed to ping 'Esstisch Rechts 1' (attempt 1/1, ZCL command 0x00158d0002ca7040/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '57482'.))
[03:12:05] INFO: Preparing to start...
[03:12:05] INFO: Socat not enabled
[03:12:06] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[03:12:31] INFO: Preparing to start...
[03:12:31] INFO: Socat not enabled
[03:12:32] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[03:12:58] INFO: Preparing to start...
[03:12:58] INFO: Socat not enabled
[03:12:59] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-12-17 03:14:02] warning: z2m: Failed to ping 'Esstisch Links 4' (attempt 1/1, ZCL command 0x00158d0002cabe0c/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '49194'.))
[2024-12-17 03:14:16] warning: z2m: Failed to ping 'Flur oben hinten' (attempt 1/1, ZCL command 0x00158d00041badb0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '43270'.))
[2024-12-17 03:14:27] warning: z2m: Failed to ping 'Schlafzimmer 1' (attempt 1/1, ZCL command 0x00158d00041b9bb5/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '24184'.))
[2024-12-17 03:14:52] warning: z2m: Failed to ping 'Gartenkugel vorn' (attempt 1/1, ZCL command 0x00158d0002cbcd84/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '57'.))
[05:16:37] INFO: Preparing to start...
[05:16:38] INFO: Socat not enabled
[05:16:38] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[05:17:09] INFO: Preparing to start...
[05:17:10] INFO: Socat not enabled
[05:17:10] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[07:23:16] INFO: Preparing to start...
[07:23:16] INFO: Socat not enabled
[07:23:17] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-12-17 07:46:02] error: z2m: Publish 'set' 'brightness' to 'Gartenkugel vorn' failed: 'Error: ZCL command 0x00158d0002cbcd84/1 genLevelCtrl.moveToLevelWithOnOff({"level":254,"transtime":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '57'.)'
[2024-12-17 07:46:07] error: z2m: Publish 'set' 'color_temp' to 'Gartenkugel vorn' failed: 'Error: ZCL command 0x00158d0002cbcd84/1 lightingColorCtrl.moveToColorTemp({"colortemp":370,"transtime":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"reservedBits":0,"writeUndiv":false}) failed (Delivery failed for '57'.)'

[aquashrimps]

Also, after updating the z2m, cyclic reboots began

Starting Zigbee2MQTT without watchdog.
[03:14:49] INFO: Preparing to start...
[03:14:50] INFO: Socat not enabled
[03:14:51] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[03:16:16] INFO: Preparing to start...
[03:16:17] INFO: Socat not enabled
[03:16:17] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[23:00:51] INFO: Preparing to start...
[23:00:51] INFO: Socat not enabled
[23:00:52] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-12-16 23:09:25] error: 	z2m: Publish 'set' 'scene_store' to '0xa4c138cf22957c16' failed: 'Error: Scene ID 0 cannot be used with group ID 0 (reserved).'
[03:02:19] INFO: Preparing to start...
[03:02:20] INFO: Socat not enabled
[03:02:21] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[03:14:57] INFO: Preparing to start...
[03:14:58] INFO: Socat not enabled
[03:14:58] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[04:01:23] INFO: Preparing to start...
[04:01:24] INFO: Socat not enabled
[04:01:25] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.

At another time. I was looking for the reason for the incorrect operation of the device, but even if I remove it and clean up all the tails, the reboots continue.

Starting Zigbee2MQTT without watchdog.
[20:01:12] INFO: Preparing to start...
[20:01:13] INFO: Socat not enabled
[20:01:14] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-12-13 20:02:37] error: 	zh:controller:device: Read response to 0xa4c138e7ec47d003 failed (ZCL command 0xa4c138e7ec47d003/1 genTime.readRsp({"localTime":787435337}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":1,"reservedBits":0,"transactionSequenceNumber":28,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))
[2024-12-13 20:05:03] error: 	z2m: Request 'zigbee2mqtt/bridge/request/device/remove' failed with error: 'Device 'switch_spa' does not exist'
[21:30:56] INFO: Preparing to start...
[21:30:57] INFO: Socat not enabled
[21:30:58] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.

[nict41]

I was experiencing similar issues.
For me, removing use of an external converter for my Thermostat has caused it to become stable again.