Unable to publish (edit) device values

[array81]

What happened?

I cannot change the values ​​of the devices but only read the current ones.
If I try to set a value via the graphical interface I get an error like:
Publish 'set' 'sensitivity' to '0xa4c1389da70224ca' failed: 'Error: ZCL command

Furthermore, the following information message appears every now and then during debugging:
Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "42563".

I'm not sure when the problem arose for the first time but I think it is a consequence of the update to version 1.38.0 and the simultaneous transition to the new driver ember.

Previously everything worked fine.

I use two Sonoff ZBDongle-E as coordinator and router, EmberZNet 7.4.3.0 firmware is flashed on the coordinator. I've already tried reflashing the coordinator

What did you expect to happen?

Previously I could use the graphical interface both to read the values ​​of a device and to modify some of these (depends on the device)

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.38.0

Adapter firmware version

7.4.3 [GA]

Adapter

ember

Setup

Mini PC, Debian 12, Docker

Debug log

[2024-06-29 09:25:49] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=7 frmRx=1]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=1] Added to rxQueue
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-06-29 09:25:49] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=31 Len=7]
[2024-06-29 09:25:49] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=223 messageTag=74 status=SUCCESS]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=2] Added to rxQueue
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-06-29 09:25:49] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=31 Len=27]
[2024-06-29 09:25:49] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=19903], [apsFrame={"profileId":260,"clusterId":1026,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":223}], [messageTag=74], [status=SUCCESS], [messageContents=18880b0a00]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=3] Added to rxQueue
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=4] Added to rxQueue
[2024-06-29 09:25:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-06-29 09:25:49] debug: zh:ember:ezsp: <=== [FRAME: ID=196:"INCOMING_NETWORK_STATUS_HANDLER" Seq=31 Len=8]
[2024-06-29 09:25:49] debug: zh:ember:ezsp: ezspIncomingNetworkStatusHandler(): callback called with: [errorCode=ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY], [target=19903]
[2024-06-29 09:25:49] info: zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "19903".
[2024-06-29 09:25:49] debug: zh:ember:ezsp: <=== [FRAME: ID=128:"INCOMING_ROUTE_ERROR_HANDLER" Seq=31 Len=8]
[2024-06-29 09:25:49] debug: zh:ember:ezsp: ezspIncomingRouteErrorHandler(): callback called with: [status=MAC_INDIRECT_TIMEOUT], [target=19903]
[2024-06-29 09:25:55] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Movimento Camere', payload '{"ac_status":false,"battery":94,"battery_defect":false,"battery_low":false,"device":{"applicationVersion":15,"dateCode":"20220318","friendlyName":"Movimento Camere","hardwareVersion":1,"ieeeAddr":"0x8cf681fffef51915","manufacturerID":21845,"manufacturerName":"MultIR","model":"ZP1-EN","networkAddress":31880,"powerSource":"Battery","softwareBuildID":"IR100_v1.2.0","type":"EndDevice","zclVersion":3},"last_seen":"2024-06-29T09:24:25+02:00","linkquality":176,"occupancy":false,"restore_reports":true,"supervision_reports":false,"tamper":false,"test":false,"trouble":false}'
[2024-06-29 09:26:10] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Movimento Mansarda', payload '{"ac_status":false,"battery":51,"battery_defect":false,"battery_low":false,"device":{"applicationVersion":15,"dateCode":"20220318","friendlyName":"Movimento Mansarda","hardwareVersion":1,"ieeeAddr":"0x84b4dbfffed5c855","manufacturerID":21845,"manufacturerName":"MultIR","model":"ZP1-EN","networkAddress":31366,"powerSource":"Battery","softwareBuildID":"IR100_v1.2.0","type":"EndDevice","zclVersion":3},"last_seen":"2024-06-29T09:24:40+02:00","linkquality":184,"occupancy":false,"restore_reports":true,"supervision_reports":false,"tamper":false,"test":false,"trouble":false}'
[2024-06-29 09:26:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:26:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-06-29 09:26:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=5] Added to rxQueue
[2024-06-29 09:26:53] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-06-29 09:26:53] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=31 Len=18]
[2024-06-29 09:26:53] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=37531], [sourceEui=0x8cf681fffecfd98a], [lastHopLqi=168], [lastHopRssi=-58], [relayCount=0], [relayList=]
[2024-06-29 09:26:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:26:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0]
[2024-06-29 09:26:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=0 frmNum=6] Added to rxQueue
[2024-06-29 09:26:53] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-06-29 09:26:53] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=31 Len=36]
[2024-06-29 09:26:53] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":2821,"sourceEndpoint":1,"destinationEndpoint":1,"options":320,"groupId":0,"sequence":77}], [lastHopLqi=168], [lastHopRssi=-58], [sender=37531], [bindingIndex=255], [addressIndex=255], [messageContents=18790a1d0128b81c012070]
[2024-06-29 09:26:53] debug: zh:controller: Received payload: clusterID=2821, address=37531, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=168, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":121,"commandIdentifier":10},"payload":[{"attrId":285,"dataType":40,"attrData":-72},{"attrId":284,"dataType":32,"attrData":112}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}}
[2024-06-29 09:26:53] debug: z2m: Received Zigbee message from 'Sirena Interna', type 'attributeReport', cluster 'haDiagnostic', data '{"lastMessageLqi":112,"lastMessageRssi":-72}' from endpoint 1 with groupID 0
[2024-06-29 09:26:53] debug: z2m: No converter available for 'ZR1-EN' with cluster 'haDiagnostic' and type 'attributeReport' and data '{"lastMessageLqi":112,"lastMessageRssi":-72}'
[2024-06-29 09:26:53] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Sirena Interna', payload '{"ac_status":false,"alarm":false,"battery":null,"battery_defect":false,"battery_low":false,"device":{"applicationVersion":4,"dateCode":"20220422","friendlyName":"Sirena Interna","hardwareVersion":1,"ieeeAddr":"0x8cf681fffecfd98a","manufacturerID":21845,"manufacturerName":"MultIR","model":"ZR1-EN","networkAddress":37531,"powerSource":"DC Source","softwareBuildID":"v0.3.1","type":"EndDevice","zclVersion":3},"last_seen":"2024-06-29T09:26:53+02:00","linkquality":168,"restore_reports":true,"state":"OFF","supervision_reports":true,"tamper":false,"test":false,"trouble":false,"type":"normal","volume":"high"}'
[2024-06-29 09:29:56] debug: z2m:mqtt: Received MQTT message on 'zigbee2mqtt/0xa4c1389da70224ca/set' with data '{"sensitivity":31}'
[2024-06-29 09:29:56] debug: z2m: Publishing 'set' 'sensitivity' to '0xa4c1389da70224ca'
[2024-06-29 09:29:56] debug: zh:controller:endpoint: ZCL command 0xa4c1389da70224ca/1 ssIasZone.write({"currentZoneSensitivityLevel":31}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false})
[2024-06-29 09:29:56] debug: zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-06-29 09:29:56] debug: zh:ember: ~~~> [ZCL to=42857 apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":0,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":66,"commandIdentifier":2}]
[2024-06-29 09:29:56] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=32 Len=28]
[2024-06-29 09:29:56] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=7]
[2024-06-29 09:29:56] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:29:56] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-06-29 09:29:56] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=7] Added to rxQueue
[2024-06-29 09:29:56] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-06-29 09:29:56] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=32 Len=7]
[2024-06-29 09:29:56] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=224 messageTag=75 status=SUCCESS]
[2024-06-29 09:30:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-06-29 09:30:03] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0] Added to rxQueue
[2024-06-29 09:30:03] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-06-29 09:30:03] debug: zh:ember:ezsp: <=== [FRAME: ID=128:"INCOMING_ROUTE_ERROR_HANDLER" Seq=32 Len=8]
[2024-06-29 09:30:03] debug: zh:ember:ezsp: ezspIncomingRouteErrorHandler(): callback called with: [status=MAC_INDIRECT_TIMEOUT], [target=42857]
[2024-06-29 09:30:06] debug: zh:controller:endpoint: ZCL command 0xa4c1389da70224ca/1 ssIasZone.write({"currentZoneSensitivityLevel":31}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed ({"target":42857,"apsFrame":{"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":224},"zclSequence":66,"commandIdentifier":4} timed out after 10000ms)
[2024-06-29 09:30:06] error: z2m: Publish 'set' 'sensitivity' to '0xa4c1389da70224ca' failed: 'Error: ZCL command 0xa4c1389da70224ca/1 ssIasZone.write({"currentZoneSensitivityLevel":31}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed ({"target":42857,"apsFrame":{"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":224},"zclSequence":66,"commandIdentifier":4} timed out after 10000ms)'
[2024-06-29 09:30:06] debug: z2m: Error: ZCL command 0xa4c1389da70224ca/1 ssIasZone.write({"currentZoneSensitivityLevel":31}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed ({"target":42857,"apsFrame":{"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":224},"zclSequence":66,"commandIdentifier":4} timed out after 10000ms)
at Object.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:194:23)
at EmberOneWaitress.startWaitingFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:218:50)
at Object.func (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:3676:64)
at processTicksAndRejections (node:internal/process/task_queues:95:5)
at EmberRequestQueue.dispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/requestQueue.ts:117:46)
[2024-06-29 09:30:13] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:13] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-06-29 09:30:13] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=1] Added to rxQueue
[2024-06-29 09:30:13] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-06-29 09:30:13] debug: zh:ember:ezsp: <=== [FRAME: ID=128:"INCOMING_ROUTE_ERROR_HANDLER" Seq=32 Len=8]
[2024-06-29 09:30:13] debug: zh:ember:ezsp: ezspIncomingRouteErrorHandler(): callback called with: [status=MAC_INDIRECT_TIMEOUT], [target=42857]
[2024-06-29 09:30:22] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:22] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-06-29 09:30:22] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=2] Added to rxQueue
[2024-06-29 09:30:22] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-06-29 09:30:22] debug: zh:ember:ezsp: <=== [FRAME: ID=128:"INCOMING_ROUTE_ERROR_HANDLER" Seq=32 Len=8]
[2024-06-29 09:30:22] debug: zh:ember:ezsp: ezspIncomingRouteErrorHandler(): callback called with: [status=MAC_INDIRECT_TIMEOUT], [target=42857]
[2024-06-29 09:30:24] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:24] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-06-29 09:30:24] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=3] Added to rxQueue
[2024-06-29 09:30:24] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-06-29 09:30:24] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=32 Len=29]
[2024-06-29 09:30:24] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=42857], [apsFrame={"profileId":260,"clusterId":1280,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":224}], [messageTag=75], [status=DELIVERY_FAILED], [messageContents=1042021300201f]
[2024-06-29 09:30:33] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:33] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-06-29 09:30:33] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=4] Added to rxQueue
[2024-06-29 09:30:33] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-06-29 09:30:33] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=32 Len=22]
[2024-06-29 09:30:33] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=21220], [sourceEui=0x000d6f0013023779], [lastHopLqi=96], [lastHopRssi=-76], [relayCount=2], [relayList=55065,37531]
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1]
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=5] Added to rxQueue
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-06-29 09:30:34] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=32 Len=28]
[2024-06-29 09:30:34] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":32,"sourceEndpoint":1,"destinationEndpoint":1,"options":320,"groupId":0,"sequence":241}], [lastHopLqi=100], [lastHopRssi=-75], [sender=21220], [bindingIndex=255], [addressIndex=255], [messageContents=193600]
[2024-06-29 09:30:34] debug: zh:controller: Received payload: clusterID=32, address=21220, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=100, frame={"header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":54,"commandIdentifier":0},"payload":{},"command":{"ID":0,"parameters":[],"name":"checkin"}}
[2024-06-29 09:30:34] debug: zh:controller:device: check-in from 0x000d6f0013023779: declining fast-poll
[2024-06-29 09:30:34] debug: zh:controller:endpoint: ZCL command 0x000d6f0013023779/1 genPollCtrl.checkinRsp({"startFastPolling":false,"fastPollTimeout":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false,"sendPolicy":"immediate"})
[2024-06-29 09:30:34] debug: zh:controller:endpoint: Request Queue (0x000d6f0013023779/1): send checkinRsp request immediately (sendPolicy=immediate)
[2024-06-29 09:30:34] debug: zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-06-29 09:30:34] debug: z2m: Received Zigbee message from 'Keypad Piano Terra', type 'commandCheckIn', cluster 'genPollCtrl', data '{}' from endpoint 1 with groupID 0
[2024-06-29 09:30:34] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Keypad Piano Terra', payload '{"action":null,"action_code":null,"action_transaction":null,"action_zone":null,"battery":100,"battery_low":false,"contact":true,"device":{"friendlyName":"Keypad Piano Terra","hardwareVersion":1,"ieeeAddr":"0x000d6f0013023779","manufacturerID":4335,"manufacturerName":"Universal Electronics Inc","model":"XHK1-UE","networkAddress":21220,"powerSource":"Battery","stackVersion":0,"type":"EndDevice","zclVersion":1},"last_seen":"2024-06-29T09:30:34+02:00","linkquality":100,"occupancy":false,"presence":null,"tamper":false,"temperature":24,"voltage":6100}'
[2024-06-29 09:30:34] debug: zh:ember: ~~~> [ZCL to=21220 apsFrame={"profileId":260,"clusterId":32,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":1,"direction":0,"disableDefaultResponse":false,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":67,"commandIdentifier":0}]
[2024-06-29 09:30:34] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=33 Len=27]
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=1 frmRx=6]
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=6] Added to rxQueue
[2024-06-29 09:30:34] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-06-29 09:30:34] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=33 Len=7]
[2024-06-29 09:30:34] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=225 messageTag=76 status=SUCCESS]
[2024-06-29 09:30:35] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:35] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-06-29 09:30:35] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=7] Added to rxQueue
[2024-06-29 09:30:35] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-06-29 09:30:35] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=33 Len=30]
[2024-06-29 09:30:35] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":32,"sourceEndpoint":1,"destinationEndpoint":1,"options":320,"groupId":0,"sequence":242}], [lastHopLqi=96], [lastHopRssi=-76], [sender=21220], [bindingIndex=255], [addressIndex=255], [messageContents=08430b0000]
[2024-06-29 09:30:35] debug: zh:controller: Received payload: clusterID=32, address=21220, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=96, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":67,"commandIdentifier":11},"payload":{"cmdId":0,"statusCode":0},"command":{"ID":11,"name":"defaultRsp","parameters":[{"name":"cmdId","type":32},{"name":"statusCode","type":32}]}}
[2024-06-29 09:30:35] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Keypad Piano Terra', payload '{"action":null,"action_code":null,"action_transaction":null,"action_zone":null,"battery":100,"battery_low":false,"contact":true,"device":{"friendlyName":"Keypad Piano Terra","hardwareVersion":1,"ieeeAddr":"0x000d6f0013023779","manufacturerID":4335,"manufacturerName":"Universal Electronics Inc","model":"XHK1-UE","networkAddress":21220,"powerSource":"Battery","stackVersion":0,"type":"EndDevice","zclVersion":1},"last_seen":"2024-06-29T09:30:35+02:00","linkquality":96,"occupancy":false,"presence":null,"tamper":false,"temperature":24,"voltage":6100}'
[2024-06-29 09:30:35] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:35] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-06-29 09:30:35] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=0] Added to rxQueue
[2024-06-29 09:30:35] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-06-29 09:30:35] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=33 Len=28]
[2024-06-29 09:30:35] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=21220], [apsFrame={"profileId":260,"clusterId":32,"sourceEndpoint":1,"destinationEndpoint":1,"options":4416,"groupId":0,"sequence":225}], [messageTag=76], [status=SUCCESS], [messageContents=014300000000]
[2024-06-29 09:30:47] debug: z2m: Saving state to file /app/data/state.json
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=1] Added to rxQueue
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=33 Len=22]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=42563], [sourceEui=0xa4c138e1938e96af], [lastHopLqi=124], [lastHopRssi=-69], [relayCount=2], [relayList=55065,37531]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=2 frmNum=2] Added to rxQueue
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=33 Len=30]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":10,"sourceEndpoint":1,"destinationEndpoint":1,"options":256,"groupId":0,"sequence":31}], [lastHopLqi=124], [lastHopRssi=-69], [sender=42563], [bindingIndex=255], [addressIndex=255], [messageContents=0095000700]
[2024-06-29 09:30:48] debug: zh:controller: Received payload: clusterID=10, address=42563, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=124, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":false,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":149,"commandIdentifier":0},"payload":[{"attrId":7}],"command":{"ID":0,"name":"read","parameters":[{"name":"attrId","type":33}],"response":1}}
[2024-06-29 09:30:48] debug: zh:controller:endpoint: ZCL command 0xa4c138e1938e96af/1 genTime.readRsp({"localTime":772968649}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":1,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":149,"writeUndiv":false})
[2024-06-29 09:30:48] debug: zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-06-29 09:30:48] debug: z2m: Received Zigbee message from 'Fingerbot Garage', type 'read', cluster 'genTime', data '["localTime"]' from endpoint 1 with groupID 0
[2024-06-29 09:30:48] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Fingerbot Garage', payload '{"battery":100,"delay":0,"device":{"applicationVersion":83,"dateCode":"","friendlyName":"Fingerbot Garage","hardwareVersion":1,"ieeeAddr":"0xa4c138e1938e96af","manufacturerID":4417,"manufacturerName":"_TZ3210_j4pdtz9v","model":"TS0001_fingerbot","networkAddress":42563,"powerSource":"Battery","stackVersion":0,"type":"EndDevice","zclVersion":3},"last_seen":"2024-06-29T09:30:48+02:00","linkquality":124,"lower":100,"mode":"switch","program":{"0":0,"1":255,"2":255,"3":0,"4":85,"5":0,"6":1,"7":0,"8":0,"9":5},"reverse":"ON","state":"ON","touch":"ON","upper":0}'
[2024-06-29 09:30:48] debug: zh:ember: ~~~> [ZCL to=42563 apsFrame={"profileId":260,"clusterId":10,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":1,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":149,"commandIdentifier":1}]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=34 Len=32]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=2 frmRx=3]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=3] Added to rxQueue
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=34 Len=7]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=226 messageTag=77 status=SUCCESS]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=4] Added to rxQueue
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=34 Len=33]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=42563], [apsFrame={"profileId":260,"clusterId":10,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":226}], [messageTag=77], [status=SUCCESS], [messageContents=18950107000023c990122e]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=5] Added to rxQueue
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=6] Added to rxQueue
[2024-06-29 09:30:48] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: <=== [FRAME: ID=196:"INCOMING_NETWORK_STATUS_HANDLER" Seq=34 Len=8]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: ezspIncomingNetworkStatusHandler(): callback called with: [errorCode=ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY], [target=42563]
[2024-06-29 09:30:48] info: zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "42563".
[2024-06-29 09:30:48] debug: zh:ember:ezsp: <=== [FRAME: ID=128:"INCOMING_ROUTE_ERROR_HANDLER" Seq=34 Len=8]
[2024-06-29 09:30:48] debug: zh:ember:ezsp: ezspIncomingRouteErrorHandler(): callback called with: [status=MAC_INDIRECT_TIMEOUT], [target=42563]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=7] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=34 Len=22]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=19903], [sourceEui=0xa4c13849d1eb858e], [lastHopLqi=132], [lastHopRssi=-67], [relayCount=2], [relayList=55065,37531]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=3 frmNum=0] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=34 Len=33]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":1026,"sourceEndpoint":1,"destinationEndpoint":1,"options":256,"groupId":0,"sequence":135}], [lastHopLqi=132], [lastHopRssi=-67], [sender=19903], [bindingIndex=255], [addressIndex=255], [messageContents=08890a00002988f8]
[2024-06-29 09:30:49] debug: zh:controller: Received payload: clusterID=1026, address=19903, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=132, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":137,"commandIdentifier":10},"payload":[{"attrId":0,"dataType":41,"attrData":-1912}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}}
[2024-06-29 09:30:49] debug: zh:controller:endpoint: ZCL command 0xa4c13849d1eb858e/1 msTemperatureMeasurement.defaultRsp({"cmdId":10,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":137,"writeUndiv":false})
[2024-06-29 09:30:49] debug: zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-06-29 09:30:49] debug: z2m: Received Zigbee message from 'Temperatura Congelatore Taverna', type 'attributeReport', cluster 'msTemperatureMeasurement', data '{"measuredValue":-1912}' from endpoint 1 with groupID 0
[2024-06-29 09:30:49] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Temperatura Congelatore Taverna', payload '{"battery":100,"device":{"applicationVersion":70,"dateCode":"","friendlyName":"Temperatura Congelatore Taverna","hardwareVersion":1,"ieeeAddr":"0xa4c13849d1eb858e","manufacturerID":4417,"manufacturerName":"_TZ3000_xr3htd96","model":"WSD500A","networkAddress":19903,"powerSource":"Battery","stackVersion":0,"type":"EndDevice","zclVersion":3},"humidity":41.58,"last_seen":"2024-06-29T09:30:49+02:00","linkquality":132,"temperature":-19.12,"voltage":3000}'
[2024-06-29 09:30:49] debug: zh:ember: ~~~> [ZCL to=19903 apsFrame={"profileId":260,"clusterId":1026,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":1,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":137,"commandIdentifier":11}]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=35 Len=26]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=3 frmRx=1]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=1] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=35 Len=7]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=227 messageTag=78 status=SUCCESS]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=2] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=35 Len=27]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=19903], [apsFrame={"profileId":260,"clusterId":1026,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":227}], [messageTag=78], [status=SUCCESS], [messageContents=18890b0a00]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=4 frmNum=3] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=35 Len=33]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":1029,"sourceEndpoint":1,"destinationEndpoint":1,"options":256,"groupId":0,"sequence":136}], [lastHopLqi=124], [lastHopRssi=-69], [sender=19903], [bindingIndex=255], [addressIndex=255], [messageContents=088a0a000021f60f]
[2024-06-29 09:30:49] debug: zh:controller: Received payload: clusterID=1029, address=19903, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=124, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":138,"commandIdentifier":10},"payload":[{"attrId":0,"dataType":33,"attrData":4086}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}}
[2024-06-29 09:30:49] debug: zh:controller:endpoint: ZCL command 0xa4c13849d1eb858e/1 msRelativeHumidity.defaultRsp({"cmdId":10,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":138,"writeUndiv":false})
[2024-06-29 09:30:49] debug: zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-06-29 09:30:49] debug: z2m: Received Zigbee message from 'Temperatura Congelatore Taverna', type 'attributeReport', cluster 'msRelativeHumidity', data '{"measuredValue":4086}' from endpoint 1 with groupID 0
[2024-06-29 09:30:49] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Temperatura Congelatore Taverna', payload '{"battery":100,"device":{"applicationVersion":70,"dateCode":"","friendlyName":"Temperatura Congelatore Taverna","hardwareVersion":1,"ieeeAddr":"0xa4c13849d1eb858e","manufacturerID":4417,"manufacturerName":"_TZ3000_xr3htd96","model":"WSD500A","networkAddress":19903,"powerSource":"Battery","stackVersion":0,"type":"EndDevice","zclVersion":3},"humidity":40.86,"last_seen":"2024-06-29T09:30:49+02:00","linkquality":124,"temperature":-19.12,"voltage":3000}'
[2024-06-29 09:30:49] debug: zh:ember: ~~~> [ZCL to=19903 apsFrame={"profileId":260,"clusterId":1029,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":1,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":138,"commandIdentifier":11}]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=36 Len=26]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=4 frmRx=4]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=36 Len=7]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=228 messageTag=79 status=SUCCESS]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=5] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=36 Len=27]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=19903], [apsFrame={"profileId":260,"clusterId":1029,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":228}], [messageTag=79], [status=SUCCESS], [messageContents=188a0b0a00]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=6] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=196:"INCOMING_NETWORK_STATUS_HANDLER" Seq=36 Len=8]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspIncomingNetworkStatusHandler(): callback called with: [errorCode=ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY], [target=19903]
[2024-06-29 09:30:49] info: zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "19903".
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=7] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=128:"INCOMING_ROUTE_ERROR_HANDLER" Seq=36 Len=8]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspIncomingRouteErrorHandler(): callback called with: [status=MAC_INDIRECT_TIMEOUT], [target=19903]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=0] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=196:"INCOMING_NETWORK_STATUS_HANDLER" Seq=36 Len=8]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspIncomingNetworkStatusHandler(): callback called with: [errorCode=ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY], [target=19903]
[2024-06-29 09:30:49] info: zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "19903".
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=1] Added to rxQueue
[2024-06-29 09:30:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: <=== [FRAME: ID=128:"INCOMING_ROUTE_ERROR_HANDLER" Seq=36 Len=8]
[2024-06-29 09:30:49] debug: zh:ember:ezsp: ezspIncomingRouteErrorHandler(): callback called with: [status=MAC_INDIRECT_TIMEOUT], [target=19903]
[2024-06-29 09:33:45] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:33:45] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:33:45] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=2] Added to rxQueue
[2024-06-29 09:33:45] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-06-29 09:33:45] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=36 Len=22]
[2024-06-29 09:33:45] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=21220], [sourceEui=0x000d6f0013023779], [lastHopLqi=140], [lastHopRssi=-65], [relayCount=2], [relayList=55065,37531]
[2024-06-29 09:33:45] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:33:45] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:33:45] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=3] Added to rxQueue
[2024-06-29 09:33:45] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-06-29 09:33:45] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=36 Len=32]
[2024-06-29 09:33:45] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":1,"sourceEndpoint":1,"destinationEndpoint":1,"options":320,"groupId":0,"sequence":243}], [lastHopLqi=140], [lastHopRssi=-65], [sender=21220], [bindingIndex=255], [addressIndex=255], [messageContents=18370a2000203c]
[2024-06-29 09:33:45] debug: zh:controller: Received payload: clusterID=1, address=21220, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=140, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":55,"commandIdentifier":10},"payload":[{"attrId":32,"dataType":32,"attrData":60}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}}
[2024-06-29 09:33:45] debug: z2m: Received Zigbee message from 'Keypad Piano Terra', type 'attributeReport', cluster 'genPowerCfg', data '{"batteryVoltage":60}' from endpoint 1 with groupID 0
[2024-06-29 09:33:45] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Keypad Piano Terra', payload '{"action":null,"action_code":null,"action_transaction":null,"action_zone":null,"battery":100,"battery_low":false,"contact":true,"device":{"friendlyName":"Keypad Piano Terra","hardwareVersion":1,"ieeeAddr":"0x000d6f0013023779","manufacturerID":4335,"manufacturerName":"Universal Electronics Inc","model":"XHK1-UE","networkAddress":21220,"powerSource":"Battery","stackVersion":0,"type":"EndDevice","zclVersion":1},"last_seen":"2024-06-29T09:33:45+02:00","linkquality":140,"occupancy":false,"presence":null,"tamper":false,"temperature":24,"voltage":6000}'
[2024-06-29 09:35:47] debug: z2m: Saving state to file /app/data/state.json
[2024-06-29 09:36:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:36:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:36:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=4] Added to rxQueue
[2024-06-29 09:36:53] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-06-29 09:36:53] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=36 Len=18]
[2024-06-29 09:36:53] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=37531], [sourceEui=0x8cf681fffecfd98a], [lastHopLqi=148], [lastHopRssi=-63], [relayCount=0], [relayList=]
[2024-06-29 09:36:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:36:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:36:53] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=5] Added to rxQueue
[2024-06-29 09:36:53] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=6]
[2024-06-29 09:36:53] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=36 Len=36]
[2024-06-29 09:36:53] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":2821,"sourceEndpoint":1,"destinationEndpoint":1,"options":320,"groupId":0,"sequence":78}], [lastHopLqi=152], [lastHopRssi=-62], [sender=37531], [bindingIndex=255], [addressIndex=255], [messageContents=187a0a1d0128b81c012070]
[2024-06-29 09:36:53] debug: zh:controller: Received payload: clusterID=2821, address=37531, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=152, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":122,"commandIdentifier":10},"payload":[{"attrId":285,"dataType":40,"attrData":-72},{"attrId":284,"dataType":32,"attrData":112}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}}
[2024-06-29 09:36:53] debug: z2m: Received Zigbee message from 'Sirena Interna', type 'attributeReport', cluster 'haDiagnostic', data '{"lastMessageLqi":112,"lastMessageRssi":-72}' from endpoint 1 with groupID 0
[2024-06-29 09:36:53] debug: z2m: No converter available for 'ZR1-EN' with cluster 'haDiagnostic' and type 'attributeReport' and data '{"lastMessageLqi":112,"lastMessageRssi":-72}'
[2024-06-29 09:36:53] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Sirena Interna', payload '{"ac_status":false,"alarm":false,"battery":null,"battery_defect":false,"battery_low":false,"device":{"applicationVersion":4,"dateCode":"20220422","friendlyName":"Sirena Interna","hardwareVersion":1,"ieeeAddr":"0x8cf681fffecfd98a","manufacturerID":21845,"manufacturerName":"MultIR","model":"ZR1-EN","networkAddress":37531,"powerSource":"DC Source","softwareBuildID":"v0.3.1","type":"EndDevice","zclVersion":3},"last_seen":"2024-06-29T09:36:53+02:00","linkquality":152,"restore_reports":true,"state":"OFF","supervision_reports":true,"tamper":false,"test":false,"trouble":false,"type":"normal","volume":"high"}'
[2024-06-29 09:40:47] debug: z2m: Saving state to file /app/data/state.json
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=6] Added to rxQueue
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=7]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: <=== [FRAME: ID=89:"INCOMING_ROUTE_RECORD_HANDLER" Seq=36 Len=22]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: ezspIncomingRouteRecordHandler(): callback called with: [source=19903], [sourceEui=0xa4c13849d1eb858e], [lastHopLqi=172], [lastHopRssi=-57], [relayCount=2], [relayList=55065,37531]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=5 frmNum=7] Added to rxQueue
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: <=== [FRAME: ID=69:"INCOMING_MESSAGE_HANDLER" Seq=36 Len=33]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: ezspIncomingMessageHandler(): callback called with: [type=UNICAST], [apsFrame={"profileId":260,"clusterId":1026,"sourceEndpoint":1,"destinationEndpoint":1,"options":256,"groupId":0,"sequence":137}], [lastHopLqi=172], [lastHopRssi=-57], [sender=19903], [bindingIndex=255], [addressIndex=255], [messageContents=088b0a000029b8f8]
[2024-06-29 09:40:49] debug: zh:controller: Received payload: clusterID=1026, address=19903, groupID=0, endpoint=1, destinationEndpoint=1, wasBroadcast=false, linkQuality=172, frame={"header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"manufacturerCode":null,"transactionSequenceNumber":139,"commandIdentifier":10},"payload":[{"attrId":0,"dataType":41,"attrData":-1864}],"command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}}
[2024-06-29 09:40:49] debug: zh:controller:endpoint: ZCL command 0xa4c13849d1eb858e/1 msTemperatureMeasurement.defaultRsp({"cmdId":10,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":139,"writeUndiv":false})
[2024-06-29 09:40:49] debug: zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-06-29 09:40:49] debug: z2m: Received Zigbee message from 'Temperatura Congelatore Taverna', type 'attributeReport', cluster 'msTemperatureMeasurement', data '{"measuredValue":-1864}' from endpoint 1 with groupID 0
[2024-06-29 09:40:49] info: z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/Temperatura Congelatore Taverna', payload '{"battery":100,"device":{"applicationVersion":70,"dateCode":"","friendlyName":"Temperatura Congelatore Taverna","hardwareVersion":1,"ieeeAddr":"0xa4c13849d1eb858e","manufacturerID":4417,"manufacturerName":"_TZ3000_xr3htd96","model":"WSD500A","networkAddress":19903,"powerSource":"Battery","stackVersion":0,"type":"EndDevice","zclVersion":3},"humidity":40.86,"last_seen":"2024-06-29T09:40:49+02:00","linkquality":172,"temperature":-18.64,"voltage":3000}'
[2024-06-29 09:40:49] debug: zh:ember: ~~~> [ZCL to=19903 apsFrame={"profileId":260,"clusterId":1026,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":0} header={"frameControl":{"reservedBits":0,"frameType":0,"direction":1,"disableDefaultResponse":true,"manufacturerSpecific":false},"manufacturerCode":null,"transactionSequenceNumber":139,"commandIdentifier":11}]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: ===> [FRAME: ID=52:"SEND_UNICAST" Seq=37 Len=26]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=5 frmRx=0]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=0] Added to rxQueue
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: <=== [FRAME: ID=52:"SEND_UNICAST" Seq=37 Len=7]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: ~~~> [SENT type=DIRECT apsSequence=229 messageTag=80 status=SUCCESS]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=1] Added to rxQueue
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=2]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: <=== [FRAME: ID=63:"MESSAGE_SENT_HANDLER" Seq=37 Len=27]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: ezspMessageSentHandler(): callback called with: [type=DIRECT], [indexOrDestination=19903], [apsFrame={"profileId":260,"clusterId":1026,"sourceEndpoint":1,"destinationEndpoint":1,"options":4352,"groupId":0,"sequence":229}], [messageTag=80], [status=SUCCESS], [messageContents=188b0b0a00]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=2] Added to rxQueue
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=3]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: <=== [FRAME: ID=196:"INCOMING_NETWORK_STATUS_HANDLER" Seq=37 Len=8]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: ezspIncomingNetworkStatusHandler(): callback called with: [errorCode=ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY], [target=19903]
[2024-06-29 09:40:49] info: zh:ember:ezsp: Received network/route error ROUTE_ERROR_INDIRECT_TRANSACTION_EXPIRY for "19903".
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6]
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=6 frmNum=3] Added to rxQueue
[2024-06-29 09:40:49] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=4]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: <=== [FRAME: ID=128:"INCOMING_ROUTE_ERROR_HANDLER" Seq=37 Len=8]
[2024-06-29 09:40:49] debug: zh:ember:ezsp: ezspIncomingRouteErrorHandler(): callback called with: [status=MAC_INDIRECT_TIMEOUT], [target=19903]
[2024-06-29 09:40:50] debug: zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-06-29 09:40:50] debug: zh:ember:ezsp: ===> [FRAME: ID=101:"READ_AND_CLEAR_COUNTERS" Seq=38 Len=5]
[2024-06-29 09:40:50] debug: zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=6 frmRx=4]
[2024-06-29 09:40:50] debug: zh:controller:database: Writing database to '/app/data/database.db'
[2024-06-29 09:40:50] debug: zh:ember:uart:ash: <--- [FRAME type=DATA]
[2024-06-29 09:40:50] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7]
[2024-06-29 09:40:50] debug: zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=7 frmNum=4] Added to rxQueue
[2024-06-29 09:40:50] debug: zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=5]
[2024-06-29 09:40:50] debug: zh:ember:ezsp: <=== [FRAME: ID=101:"READ_AND_CLEAR_COUNTERS" Seq=38 Len=87]
[2024-06-29 09:40:50] info: zh:ember: [NCP COUNTERS] 814,464,143,101,33,10,0,0,37,21,0,1,60,0,0,0,0,0,0,0,0,2,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
[2024-06-29 09:40:50] info: zh:ember: [ASH COUNTERS] 601,148,23,125,0,0,0,0,2813,130,130,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0