zigate: Various fixes

[Nerivec]

Fixes https://github.com/Koenkk/zigbee-herdsman/pull/1187#issuecomment-2370577122

ZDO read was done in-place, not in zigate buffalo, in LE: https://github.com/Koenkk/zigbee-herdsman/blob/97b8dc0afa1ebb6b0079cefd82049ecef3991023/src/adapter/zigate/adapter/zigateAdapter.ts#L210-L211 https://github.com/Koenkk/zigbee-herdsman/blob/97b8dc0afa1ebb6b0079cefd82049ecef3991023/src/adapter/zigate/adapter/zigateAdapter.ts#L323 https://github.com/Koenkk/zigbee-herdsman/blob/97b8dc0afa1ebb6b0079cefd82049ecef3991023/src/adapter/zigate/adapter/zigateAdapter.ts#L386-L395

CC: @devbis

[devbis]

@Nerivec Thanks! Clusters are fixed!

When I send leave request, it actually leaves the network but herdsman doesn't track that event for some reason. LeaveIndication message is there (ignored?) and then "Failed to remove device"

[2024-09-24 21:01:12] debug:    z2m:mqtt: Received MQTT message on 'zigbee2mqtt/bridge/request/device/remove' with data '{"block":false,"force":false,"id":"0xa4c138aee91d14f5","transaction":"45823-3"}'
[2024-09-24 21:01:12] info:     z2m: Removing device '0xa4c138aee91d14f5' (block: false, force: false)
[2024-09-24 21:01:12] debug:    zh:zigate:driver: ZDO LEAVE_REQUEST(cmd code: 76) a4c138aee91d14f50000
[2024-09-24 21:01:12] debug:    zh:zigate:driver: ZDO {"msgCodeBytes":{"type":"Buffer","data":[0,76]},"msgLengthBytes":{"type":"Buffer","data":[0,10]},"checksumBytes":{"type":"Buffer","data":[160]},"msgPayloadBytes":{"type":"Buffer","data":[164,193,56,174,233,29,20,245,0,0]},"rssiBytes":{"type":"Buffer","data":[]},"msgLengthOffset":0}
[2024-09-24 21:01:12] debug:    zh:zigate:driver: <-- ZDO send command 0102104c0210021aa0a4c138aee91d14f50210021003
[2024-09-24 21:01:12] debug:    zh:zigate:frame: {"msgCodeBytes":{"type":"Buffer","data":[128,0]},"msgLengthBytes":{"type":"Buffer","data":[0,9]},"checksumBytes":{"type":"Buffer","data":[199]},"msgPayloadBytes":{"type":"Buffer","data":[0,0,0,76,0,0,2,0]},"rssiBytes":{"type":"Buffer","data":[0]},"msgLengthOffset":-1}
[2024-09-24 21:01:12] debug:    zh:zigate:driver: --> parsed frame >>>> Status 0x8000 <<<<
[2024-09-24 21:01:12] debug:    zh:zigate:object: Last bytes of data were not parsed 00 00 00 4c 00 00 02 00
[2024-09-24 21:01:12] debug:    zh:zigate:driver: {"status":0,"sequence":0,"packetType":76}
[2024-09-24 21:01:12] debug:    zh:zigate:frame: {"msgCodeBytes":{"type":"Buffer","data":[128,72]},"msgLengthBytes":{"type":"Buffer","data":[0,10]},"checksumBytes":{"type":"Buffer","data":[219]},"msgPayloadBytes":{"type":"Buffer","data":[164,193,56,174,233,29,20,245,0]},"rssiBytes":{"type":"Buffer","data":[255]},"msgLengthOffset":-1}
[2024-09-24 21:01:12] debug:    zh:zigate:driver: --> parsed frame >>>> LeaveIndication 0x8048 <<<<
[2024-09-24 21:01:12] debug:    zh:zigate:driver: {"extendedAddress":"0xa4c138aee91d14f5","rejoin":0}
[2024-09-24 21:01:12] debug:    zh:zigate: LeaveIndication {"_code":32840,"_payload":{"extendedAddress":"0xa4c138aee91d14f5","rejoin":0},"_parameters":[{"name":"extendedAddress","parameterType":3},{"name":"rejoin","parameterType":0}],"_frame":{"msgCodeBytes":{"type":"Buffer","data":[128,72]},"msgLengthBytes":{"type":"Buffer","data":[0,10]},"checksumBytes":{"type":"Buffer","data":[219]},"msgPayloadBytes":{"type":"Buffer","data":[164,193,56,174,233,29,20,245,0]},"rssiBytes":{"type":"Buffer","data":[255]},"msgLengthOffset":-1}}
[2024-09-24 21:01:12] debug:    zh:controller: Device leave '0xa4c138aee91d14f5'
[2024-09-24 21:01:12] debug:    zh:controller: Removing device from database '0xa4c138aee91d14f5'
[2024-09-24 21:01:12] debug:    zh:controller:database: Writing database to '/Users/ivan.belokobylskiy/projects/zigbee2mqtt/data/database.db'
[2024-09-24 21:01:12] warning:  z2m: Device '0xa4c138aee91d14f5' left the network
[2024-09-24 21:01:12] info:     z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"message":"left_network","meta":{"friendly_name":"0xa4c138aee91d14f5"},"type":"device_removed"}'
[2024-09-24 21:01:12] info:     z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"0xa4c138aee91d14f5","ieee_address":"0xa4c138aee91d14f5"},"type":"device_leave"}'
[2024-09-24 21:01:22] error:    z2m: Request 'zigbee2mqtt/bridge/request/device/remove' failed with error: 'Failed to remove device '0xa4c138aee91d14f5' (block: false, force: false) (Error: {"clusterId":32820,"target":21502} after 10000ms)'
[2024-09-24 21:01:22] debug:    z2m: Error: Failed to remove device '0xa4c138aee91d14f5' (block: false, force: false) (Error: {"clusterId":32820,"target":21502} after 10000ms)
    at Bridge.removeEntity (/Users/ivan.belokobylskiy/projects/zigbee2mqtt/lib/extension/bridge.ts:718:19)
    at Bridge.deviceRemove (/Users/ivan.belokobylskiy/projects/zigbee2mqtt/lib/extension/bridge.ts:259:16)
    at Bridge.onMQTTMessage (/Users/ivan.belokobylskiy/projects/zigbee2mqtt/lib/extension/bridge.ts:200:34)
    at EventEmitter.wrappedCallback (/Users/ivan.belokobylskiy/projects/zigbee2mqtt/lib/eventBus.ts:206:17)
[2024-09-24 21:01:22] info:     z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/response/device/remove', payload '{"data":{},"error":"Failed to remove device '0xa4c138aee91d14f5' (block: false, force: false) (Error: {\"clusterId\":32820,\"target\":21502} after 10000ms)","status":"error","transaction":"45823-3"}'

[Nerivec]

@devbis Looks like LEAVE_RESPONSE is missing in the stack (can't find it in the zigate docs either). So, this should bypass it (no more waitress timeout), and LeaveIndication will take care of ensuring the deletion.

[Koenkk]

Thanks!

[devbis]

@Nerivec

I tested the latest revision.

[2024-09-24 22:23:49] debug:    zh:zigate:driver: --> parsed frame >>>> LeaveIndication 0x8048 <<<<
[2024-09-24 22:23:49] debug:    zh:zigate:driver: {"extendedAddress":"0xa4c138aee91d14f5","rejoin":0}
[2024-09-24 22:23:49] debug:    zh:zigate: LeaveIndication {"_code":32840,"_payload":{"extendedAddress":"0xa4c138aee91d14f5","rejoin":0},"_parameters":[{"name":"extendedAddress","parameterType":3},{"name":"rejoin","parameterType":0}],"_frame":{"msgCodeBytes":{"type":"Buffer","data":[128,72]},"msgLengthBytes":{"type":"Buffer","data":[0,10]},"checksumBytes":{"type":"Buffer","data":[219]},"msgPayloadBytes":{"type":"Buffer","data":[164,193,56,174,233,29,20,245,0]},"rssiBytes":{"type":"Buffer","data":[255]},"msgLengthOffset":-1}}
[2024-09-24 22:23:49] debug:    zh:controller: Device leave '0xa4c138aee91d14f5'
[2024-09-24 22:23:49] debug:    zh:controller: Device leave is from unknown or already deleted device '0xa4c138aee91d14f5'

It look like LeaveIndication comes from already deleted device.

I made an additional test: powered off the device and deleted it from z2m. It was deleted immediately, like "force" flag was set, but it wasn't. So the device is unaware that it is not in the network. Logs are populating with "Data is from unknown device with address '10166', skipping..."

I think that command should treat LeaveIndication as LEAVE_RESPONSE that you mentioned.

[Nerivec]

Yes, LeaveIndication confirms that the device was deleted (gets ignored), and if not, ensures it. Should always be the first case in a "proper" scenario.

The two are not compatible though, due to the limited data compared to DataIndication with proper ZDO cluster.

[devbis]

In the 1.40.1 it waited for LeaveIndication to complete the deletion in the graceful mode. And now force = true/false behaves the same way.

[Nerivec]

And now force = true/false behaves the same way.

Not quite, force=true doesn't actually send LEAVE_REQUEST at all, it just removes from database.

https://github.com/Koenkk/zigbee-herdsman/pull/1204 should offer a more graceful solution.