Failure send addTransientLinkKey with EZSP

[skinkie]

For me this is the cause why zigbee2mqtt crashes.

Error: Failure send addTransientLinkKey:{"type":"Buffer","data":[redacted]}
    at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:529:23
    at Queue.executeNext (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:32:32)

Running on the zigbee2mqtt develop branch with ezsp.

[kirovilya]

need more logs - record herdsman logs please

[skinkie]

@kirovilya I am going to enable it, no idea what will trigger it

[kirovilya]

there are ideas - connection falls off. you did not write which coordinator you are using: stick or remote port. you didn't write the z2m version: you need to try on the latest version 1.30.0

[skinkie]

@kirovilya I did write which version, the latest develop branch. This is running via a remote port.

[kirovilya]

Fine. this means that in the logs it will be seen that in case of errors or loss of connection, several reconnection attempts are made. you probably still have pairing mode on all the time and therefore the addTransientLinkKey command is executed every few minutes

[skinkie]

Shall I keep it on for now, or disable it to exclude it as cause?

[kirovilya]

that's not the cause - connection problem with remote port - that's the cause

[kirovilya]

but, an automatic reconnection should be performed - I wanted to see this in the logs

[skinkie]

that's not the cause - connection problem with remote port - that's the cause

I would be surprised that a raspberry pi connected to a virtually idle switch, which then connects the remote device, would cause network interruptions. But you are right: even if that would be the case, reconnection would be the right thing to do.

[kirovilya]

the addTransientLinkKey command is sent to the coordinator chip, not to the zigbee device. So I think it's a connection issue. but you need to look at what was in the logs before and after ...

[skinkie]

There we go:

  zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"getNodeId","_id_":39,"_isRequest_":true} +0ms
  zigbee-herdsman:adapter:ezsp:uart --> DATA (6,7,0): 1e00012700 +2ms
  zigbee-herdsman:adapter:ezsp:uart --> [675c21a9732abd857e] +5ms
  zigbee-herdsman:adapter:ezsp:uart -?- waiting (7) +1ms
  zigbee-herdsman:adapter:ezsp:uart <-- [775ca1a9732a15b2] +13ms
  zigbee-herdsman:adapter:ezsp:uart <-- [3bf77e] +42ms
  zigbee-herdsman:adapter:ezsp:uart <-- DATA (7,7,0): 775ca1a9732a15b23bf77e +48ms
  zigbee-herdsman:adapter:ezsp:uart --> ACK  (0) +0ms
  zigbee-herdsman:adapter:ezsp:uart --> [8070787e] +50ms
  zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 1e800127000000 +52ms
  zigbee-herdsman:adapter:ezsp:ezsp <== 0x27: {"_id_":39,"_cls_":"getNodeId","_isRequest_":false,"nodeId":0} +0ms
  zigbee-herdsman:adapter:ezsp:uart -+- waiting (7) success +3ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> getEui64: null +2ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"getEui64","_id_":38,"_isRequest_":true} +0ms
  zigbee-herdsman:adapter:ezsp:uart --> DATA (7,0,0): 1f00012600 +1ms
  zigbee-herdsman:adapter:ezsp:uart --> [705d21a9722af6207e] +4ms
  zigbee-herdsman:adapter:ezsp:uart -?- waiting (0) +2ms
  zigbee-herdsman:adapter:ezsp:uart <-- [005da1a9722a77f0] +12ms
  zigbee-herdsman:adapter:ezsp:uart <-- [146ab557a809f1797e] +42ms
  zigbee-herdsman:adapter:ezsp:uart <-- DATA (0,0,0): 005da1a9722a77f0146ab557a809f1797e +48ms
  zigbee-herdsman:adapter:ezsp:uart --> ACK  (1) +0ms
  zigbee-herdsman:adapter:ezsp:uart --> [8160597e] +50ms
  zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 1f8001260062424dfeff72025c +51ms
  zigbee-herdsman:adapter:ezsp:ezsp <== 0x26: {"_id_":38,"_cls_":"getEui64","_isRequest_":false,"eui64":{"type":"Buffer","data":[92,2,114,255,254,77,66,98]}} +1ms
  zigbee-herdsman:adapter:ezsp:uart -+- waiting (0) success +3ms
  zigbee-herdsman:adapter:ezsp:driv Network ready +108ms
  zigbee-herdsman:adapter:ezsp:debg Device join request received: 0 5c0272fffe4d4262 +4s
  zigbee-herdsman:adapter:ezsp:debg Requesting 'Node Descriptor' for '0' +0ms
  zigbee-herdsman:adapter:ezsp:driv ZDO Node_Desc_req params: {"dstaddr":0} +2ms
  zigbee-herdsman:adapter:ezsp:driv EZSP nwk=0, IEEE=0x5c0272fffe4d4262 +1ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> getKey: {"keyType":1} +4ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"getKey","_id_":106,"_isRequest_":true,"keyType":1} +1ms
  zigbee-herdsman:adapter:ezsp:uart --> DATA (0,1,0): 2000016a0001 +5ms
  zigbee-herdsman:adapter:ezsp:uart --> [016221a93e2a14432f7e] +7ms
  zigbee-herdsman:adapter:ezsp:uart -?- waiting (1) +1ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> setExtendedTimeout: {"remoteEui64":{"_value":{"type":"Buffer","data":[92,2,114,255,254,77,66,98]}},"extendedTimeout":true} +2ms
  zigbee-herdsman:adapter:ezsp:uart <-- [7d3162a1a93e2a15] +17ms
  zigbee-herdsman:adapter:ezsp:uart <-- [a859953b5b0289028d57766e07165cc816e24363c9fe7d5e3fa7ebcdde0dcdb23924a7d035f0d17e] +42ms
  zigbee-herdsman:adapter:ezsp:uart <-- DATA (1,1,0): 1162a1a93e2a15a859953b5b0289028d57766e07165cc816e24363c9fe7e3fa7ebcdde0dcdb23924a7d035f0d17e +50ms
  zigbee-herdsman:adapter:ezsp:uart --> ACK  (2) +1ms
  zigbee-herdsman:adapter:ezsp:uart --> [82503a7e] +52ms
  zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 2080016a00001a0001717ea8dc90c4cb3849acfb92af9d1f8500400200000000000062424dfeff72025c +52ms
  zigbee-herdsman:adapter:ezsp:ezsp <== 0x6a: {"_id_":106,"_cls_":"getKey","_isRequest_":false,"status":0,"keyStruct":{"bitmask":26,"type":1,"key":{"contents":[113,126,168,220,144,196,203,56,73,172,251,146,175,157,31,133]},"outgoingFrameCounter":147456,"incomingFrameCounter":0,"sequenceNumber":0,"partnerEUI64":{"type":"Buffer","data":[92,2,114,255,254,77,66,98]}}} +1ms
  zigbee-herdsman:adapter:ezsp:uart -+- waiting (1) success +3ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"setExtendedTimeout","_id_":126,"_isRequest_":true,"remoteEui64":{"_value":{"type":"Buffer","data":[92,2,114,255,254,77,66,98]}},"extendedTimeout":true} +1ms
  zigbee-herdsman:adapter:ezsp:uart --> DATA (1,2,0): 2100017e0062424dfeff72025c01 +1ms
  zigbee-herdsman:adapter:ezsp:uart --> [126321a92a2a77f0146ab557a809938b457e] +5ms
  zigbee-herdsman:adapter:ezsp:uart -?- waiting (2) +1ms
  zigbee-herdsman:adapter:ezsp:driv TRUST_CENTER_LINK_KEY: {"_id_":106,"_cls_":"getKey","_isRequest_":false,"status":0,"keyStruct":{"bitmask":26,"type":1,"key":{"contents":[113,126,168,220,144,196,203,56,73,172,251,146,175,157,31,133]},"outgoingFrameCounter":147456,"incomingFrameCounter":0,"sequenceNumber":0,"partnerEUI64":{"type":"Buffer","data":[92,2,114,255,254,77,66,98]}}} +60ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> getKey: {"keyType":3} +3ms
  zigbee-herdsman:adapter:ezsp:uart <-- [2263a1a92a2a949c] +14ms
  zigbee-herdsman:adapter:ezsp:uart <-- [7e] +41ms
  zigbee-herdsman:adapter:ezsp:uart <-- DATA (2,2,0): 2263a1a92a2a949c7e +49ms
  zigbee-herdsman:adapter:ezsp:uart --> ACK  (3) +0ms
  zigbee-herdsman:adapter:ezsp:uart --> [83401b7e] +49ms
  zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 2180017e00 +49ms
  zigbee-herdsman:adapter:ezsp:ezsp <== 0x7e: {"_id_":126,"_cls_":"setExtendedTimeout","_isRequest_":false} +1ms
  zigbee-herdsman:adapter:ezsp:uart -+- waiting (2) success +3ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"getKey","_id_":106,"_isRequest_":true,"keyType":3} +1ms
  zigbee-herdsman:adapter:ezsp:uart --> DATA (2,3,0): 2200016a0003 +1ms
  zigbee-herdsman:adapter:ezsp:uart --> [236021a93e2a16e6387e] +4ms
  zigbee-herdsman:adapter:ezsp:uart -?- waiting (3) +1ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> sendUnicast: {"type":0,"indexOrDestination":0,"apsFrame":{"clusterId":2,"profileId":0,"sequence":2,"sourceEndpoint":0,"destinationEndpoint":0,"groupId":0,"options":320},"messageTag":3,"message":{"type":"Buffer","data":[2,0,0]}} +3ms
  zigbee-herdsman:adapter:ezsp:uart <-- [3360a1a93e2a15b1] +13ms
  zigbee-herdsman:adapter:ezsp:uart --> Error: Error: {"sequence":4} after 2000ms +20ms
  zigbee-herdsman:adapter:ezsp:uart -!- break rewaiting (4) +0ms
  zigbee-herdsman:adapter:ezsp:uart Can't resend DATA frame (3,4,1): 230001340000000000000200000040010000020303020000 +1ms
  zigbee-herdsman:adapter:ezsp:driv Reset connection. Try 0 +74ms
  zigbee-herdsman:adapter:ezsp:driv Stop driver +1ms
  zigbee-herdsman:adapter:ezsp:ezsp Stop ezsp +21ms
  zigbee-herdsman:adapter:ezsp:erro Request error Error: Failure send sendUnicast:{"type":"Buffer","data":[35,0,1,52,0,0,0,0,0,0,2,0,0,0,64,1,0,0,2,3,3,2,0,0]}: Error: Failure send sendUnicast:{"type":"Buffer","data":[35,0,1,52,0,0,0,0,0,0,2,0,0,0,64,1,0,0,2,3,3,2,0,0]}
  zigbee-herdsman:adapter:ezsp:erro     at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:529:23
  zigbee-herdsman:adapter:ezsp:erro     at Queue.executeNext (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:32:32) +3s
  zigbee-herdsman:adapter:ezsp:erro zdoRequest error +1ms
  zigbee-herdsman:adapter:ezsp:debg Node descriptor request for '0' failed (Error: ZdoRequest error), retry +143ms
Error: ZdoRequest error
    at Driver.zdoRequest (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:571:19)
    at EZSPAdapter.nodeDescriptorInternal (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:373:28)
    at Object.func (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:363:32)
    at Queue.executeNext (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:32:32)

According to npm i this would be zigbee-herdsman-0.14.90.tgz

[kirovilya]

Thanks for the log, I see that the error has changed. for some reason, the response to the command did not come ... and for some reason the reconnection did not occur. after this error there was no automatic switching? should have been in a few seconds

[skinkie]

What I noticed in my home assistant is that there is a connection loss to a power plug at 2:04am, the system remains working. Then something happens for that device at 4:40am which is when the entire system fails.

[kirovilya]

I see that the data packet comes last:

<-- [3360a1a93e2a15b1] +13ms

but this is not a complete package, because, there is no terminating byte 7e... and immediately after that an error waiting for a response is thrown. I suggest trying to increase the response timeout. in the zigbee-herdsman/dist/adapter/ezsp/driver/uart.js file, change the number 2000 (line 355) to 5000:

    public waitFor(sequence, timeout = 5000) {

[skinkie]

@kirovilya this is with the 5000.

 zigbee-herdsman:adapter:ezsp:ezsp <== 0x34: {"_id_":52,"_cls_":"sendUnicast","_isRequest_":false,"status":0,"sequence":47} +0ms
  zigbee-herdsman:adapter:ezsp:uart -+- waiting (6) success +3ms
  zigbee-herdsman:adapter:ezsp:uart <-- [266fb1a97d312a15] +190ms
  zigbee-herdsman:adapter:ezsp:uart <-- [b658904124ab5593499c0e4b1c21ca9874e8de3e88f97b3f8602cdd66a8fdec7dbded769a5462341a47e366fb1a96b2a157d5e5d904b21a15493099c4e2784e9ce67c9627e] +43ms
  zigbee-herdsman:adapter:ezsp:uart <-- DATA (2,6,0): 266fb1a9112a15b658904124ab5593499c0e4b1c21ca9874e8de3e88f97b3f8602cdd66a8fdec7dbded769a5462341a47e +230ms
  zigbee-herdsman:adapter:ezsp:uart --> ACK  (3) +1ms
  zigbee-herdsman:adapter:ezsp:uart --> [83401b7e] +233ms
  zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 2d90014500000401040b010100010000406cb7cc04ffff15185d0105050021e9000805002100000b0500290000 +233ms
  zigbee-herdsman:adapter:ezsp:ezsp <== 0x45: {"_id_":69,"_cls_":"incomingMessageHandler","_isRequest_":false,"type":0,"apsFrame":{"profileId":260,"clusterId":2820,"sourceEndpoint":1,"destinationEndpoint":1,"options":256,"groupId":0,"seq
uence":64},"lastHopLqi":108,"lastHopRssi":-73,"sender":1228,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[24,93,1,5,5,0,33,233,0,8,5,0,33,0,0,11,5,0,41,0,0]}} +1ms
  zigbee-herdsman:adapter:ezsp:debg processMessage: {"messageType":0,"apsFrame":{"profileId":260,"clusterId":2820,"sourceEndpoint":1,"destinationEndpoint":1,"options":256,"groupId":0,"sequence":64},"lqi":108,"rssi":-73,"sender":1228,"bindingIndex":255,"addressIndex":255,"message":{"type":"Buffer","data":[24,93,1,5,5,0,33,233,0,8,5,0,33,0,0,11,5,0,41,0,0]}} +487ms
  zigbee-herdsman:controller:log Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":93,"manufacturerCode":null,"commandIdentifier":1},"Payload":[{"attrId":1285,"status":0,"dataType":33,"attrData":233},{"attrId":1288,"status":0,"dataType":33,"attrData":0},{"attrId":1291,"status":0,"dataType":41,"attrData":0}],"Command":{"ID":1,"name":"readRsp","parameters":[{"name":"attrId","type":33},{"name":"status","type":32},{"name":"dataType","type":32,"conditions":[{"type":"statusEquals","value":0}]},{"name":"attrData","type":1000,"conditions":[{"type":"statusEquals","value":0}]}]}},"address":1228,"endpoint":1,"linkquality":108,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}' +19s
Zigbee2MQTT:debug 2023-02-08 21:48:14: Received Zigbee message from 'Powerplug 3', type 'readResponse', cluster 'haElectricalMeasurement', data '{"activePower":0,"rmsCurrent":0,"rmsVoltage":233}' from endpoint 1 with groupID 0
  zigbee-herdsman:adapter:ezsp:uart <-- DATA (3,6,0): 366fb1a96b2a157e5d904b21a15493099c4e2784e9ce67c9627e +510ms
  zigbee-herdsman:adapter:ezsp:uart --> ACK  (4) +0ms
  zigbee-herdsman:adapter:ezsp:uart --> [8430fc7e] +511ms
  zigbee-herdsman:adapter:ezsp:ezsp <== Frame: 2d90013f0000cc040401040b0101400000002f040000 +510ms
  zigbee-herdsman:adapter:ezsp:ezsp <== 0x3f: {"_id_":63,"_cls_":"messageSentHandler","_isRequest_":false,"type":0,"indexOrDestination":1228,"apsFrame":{"profileId":260,"clusterId":2820,"sourceEndpoint":1,"destinationEndpoint":1,"options":64,"groupId":0,"sequence":47},"messageTag":4,"status":0,"message":{"type":"Buffer","data":[]}} +1ms
Zigbee2MQTT:info  2023-02-08 21:48:15: MQTT publish: topic 'zigbee2mqtt/Powerplug 3', payload '{"child_lock":"UNLOCK","current":0,"energy":53.89,"indicator_mode":"off/on","linkquality":108,"power":0,"power_outage_memory":"on","state":"ON","update":{"installed_version":-1,"latest_version":-1,"state":"idle"},"update_available":null,"voltage":233}'
  zigbee-herdsman:adapter:ezsp:uart <-- [3e6fb1a96b2a157d5e5d904b21a15493099c4e2784e9ce67d1597e] +596ms
  zigbee-herdsman:adapter:ezsp:uart <-- DATA (3,6,1): 3e6fb1a96b2a157e5d904b21a15493099c4e2784e9ce67d1597e +85ms
  zigbee-herdsman:adapter:ezsp:uart --> ACK  (4) +1ms
  zigbee-herdsman:adapter:ezsp:uart --> [8430fc7e] +86ms
  zigbee-herdsman:adapter:ezsp:uart Skipping the packet as repeated (4) +2ms
  zigbee-herdsman:adapter:ezsp:uart --> Error: Error: {"sequence":2} after 5000ms +906ms
  zigbee-herdsman:adapter:ezsp:uart -!- break rewaiting (2) +2ms
  zigbee-herdsman:adapter:ezsp:uart Can't resend DATA frame (1,6,1): 990001340000239d0401000001014001000043440518370b0a00 +0ms
  zigbee-herdsman:adapter:ezsp:driv Reset connection. Try 0 +5s
  zigbee-herdsman:adapter:ezsp:driv Stop driver +1ms
  zigbee-herdsman:adapter:ezsp:ezsp Stop ezsp +994ms
  zigbee-herdsman:adapter:ezsp:ezsp ==> {"_cls_":"nop","_id_":5,"_isRequest_":true} +141ms
  zigbee-herdsman:adapter:ezsp:uart --> DATA (2,6,0): 9a00010500 +143ms
  zigbee-herdsman:adapter:ezsp:uart --> [26d821a9512a59677e] +1s
  zigbee-herdsman:adapter:ezsp:uart -?- waiting (3) +2ms
  zigbee-herdsman:adapter:ezsp:erro Request error Error: Failure send sendUnicast:{"type":"Buffer","data":[153,0,1,52,0,0,35,157,4,1,0,0,1,1,64,1,0,0,67,68,5,24,55,11,10,0]}: Error: Failure send sendUnicast:{"type":"Buffer","data":[153,0,1,52,0,0,35,157,4,1,0,0,1,1,64,1,0,0,67,68,5,24,55,11,10,0]}
  zigbee-herdsman:adapter:ezsp:erro     at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:535:23
  zigbee-herdsman:adapter:ezsp:erro     at Queue.executeNext (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:32:32) +1d
  zigbee-herdsman:adapter:ezsp:debg sendZclFrameToEndpointInternal 0xe0798dfffeb911af:40227/1 (0,0,1) +2s
  zigbee-herdsman:adapter:ezsp:erro Request error TypeError: Cannot read properties of undefined (reading 'ezspV'): TypeError: Cannot read properties of undefined (reading 'ezspV')
  zigbee-herdsman:adapter:ezsp:erro     at Driver.request (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:467:27)
  zigbee-herdsman:adapter:ezsp:erro     at EZSPAdapter.sendZclFrameToEndpointInternal (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:460:35) +211ms
  zigbee-herdsman:controller:endpoint DefaultResponse 0xe0798dfffeb911af/1 0(10, {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (sendZclFrameToEndpointInternal error) +1d
  zigbee-herdsman:controller:device:error Default response to 0xe0798dfffeb911af failed +1d
  zigbee-herdsman:controller:endpoint Read 0xe0798dfffeb911af/1 haElectricalMeasurement(["rmsVoltage","rmsCurrent","activePower"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (sendZclFrameToEndpointInternal error) +1ms
TypeError: Cannot read properties of undefined (reading 'execCommand')
    at Driver.addTransientLinkKey (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:677:26)
    at Driver.preJoining (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:609:35)
    at Object.func (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:237:29)
    at Queue.executeNext (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:32:42)
    at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:21:18
    at new Promise (<anonymous>)
    at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:19:16)
    at EZSPAdapter.permitJoin (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:234:34)
    at Timeout._onTimeout (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/controller.ts:251:36)
    at listOnTimeout (node:internal/timers:564:17)

[kirovilya]

@skinkie Thank you. A strange error, a reconnection should have been performed ... I will understand.

[kirovilya]

@skinkie please check on the latest dev/edge version of z2m, I made some changes for ezsp adapter

[skinkie]

@kirovilya still crashes, no logs yet.

[skinkie]

@kirovilya

Zigbee2MQTT:info  2023-02-12 04:51:48: MQTT publish: topic 'zigbee2mqtt/Powerplug 4', payload '{"child_lock":null,"current":0.08,"energy":24.12,"indicator_mode":null,"linkquality":232,"power":0,"power_outage_memory":null,"state":"ON","update":{"installed_version":-1,"latest_version":-1,"state":"idle"},"update_available":null,"voltage":230}'
Error: Connection not initialized
    at Ezsp.execCommand (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/ezsp.ts:524:19)
    at Driver.addTransientLinkKey (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:678:26)
    at Driver.preJoining (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:610:35)
    at Object.func (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:237:29)
    at Queue.executeNext (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:32:42)
    at /opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:21:18
    at new Promise (<anonymous>)
    at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:19:16)
    at EZSPAdapter.permitJoin (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:234:34)
    at Timeout._onTimeout (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/controller.ts:251:36)

[skinkie]

In addition:

"ON","update":{"installed_version":-1,"latest_version":-1,"state":"idle"},"update_available":null,"voltage":235}'
Error: ZdoRequest error
    at Driver.zdoRequest (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/driver/driver.ts:572:19)
    at EZSPAdapter.nodeDescriptorInternal (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:373:28)
    at Object.func (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/ezsp/adapter/ezspAdapter.ts:363:32)
    at Queue.executeNext (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:32:32)

[kirovilya]

@skinkie :( I don't understand why your connection is lost like this... and not restored.

[skinkie]

Lets say what I noticed since about one week is that Homeassistant for some reason runs completely out of memory. I have no indication this happens for zigbee2mqtt. And zigbee2mqtt crashing happens for me independently of home assistant getting killed by Linux.

[skinkie]

@kirovilya I think I have found the root cause since I did not have any issues anymore. I have my raspberry pi connected to a decent powersource (Ikea 3A adapter) but the MicroUSB cable seemed to be degraded. Effectively the Pi complained about 'undervoltage' and started to reduce CPU frequency etc. After replacing the cable I have not had any issues with power anymore. Zigbee was stable too. So it seems timing is critical, and it does have issues recovering.