Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

zigate: Various fixes #1203

Merged
merged 3 commits into from
Sep 24, 2024
Merged

zigate: Various fixes #1203

merged 3 commits into from
Sep 24, 2024

Conversation

Nerivec
Copy link
Collaborator

@Nerivec Nerivec commented Sep 24, 2024

Fixes #1187 (comment)

ZDO read was done in-place, not in zigate buffalo, in LE:

networkAddress: entry.readUInt16LE(16),
ieeeAddr: new Buffalo(extAddr).readIeeeAddr(),

const manufacturer = buf.readUInt16LE(7);

for (let i = 0; i < inCount; i++) {
inClusters[i] = buf.readUInt16LE(cIndex);
cIndex += 2;
}
const outCount = buf.readUInt8(12 + inCount * 2);
const outClusters = [];
cIndex = 13 + inCount * 2;
for (let l = 0; l < outCount; l++) {
outClusters[l] = buf.readUInt16LE(cIndex);
cIndex += 2;

CC: @devbis

@devbis
Copy link
Contributor

devbis commented Sep 24, 2024

@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
Copy link
Collaborator Author

Nerivec commented Sep 24, 2024

@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 Koenkk merged commit 45c0f26 into Koenkk:master Sep 24, 2024
1 check passed
@Koenkk
Copy link
Owner

Koenkk commented Sep 24, 2024

Thanks!

@Nerivec Nerivec deleted the zigate-fixes branch September 24, 2024 19:17
@devbis
Copy link
Contributor

devbis commented Sep 24, 2024

@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
Copy link
Collaborator Author

Nerivec commented Sep 24, 2024

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
Copy link
Contributor

devbis commented Sep 24, 2024

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
Copy link
Collaborator Author

Nerivec commented Sep 24, 2024

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.

#1204 should offer a more graceful solution.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants