ptvoinfo / zigbee-configurable-firmware

PTVO firmware for CC2530, CC2531, and CC2652 Zigbee chips
https://ptvo.info/zigbee-configurable-firmware-features/
MIT License
209 stars 22 forks source link

PSM switch seem to often crash and "announced itself" after several presses #292

Open Flavien opened 4 months ago

Flavien commented 4 months ago

I have a simple switch configured with PSM (simple battery-powered CC2530 board). After pressing the switch a few times in quick succession, the switch seem to often crash and restart, as the logs below show:

[2024-07-01 17:54:48] debug:    z2m: Device 'bedroom/switch' announced itself
[2024-07-01 17:54:48] info:     z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"bedroom/switch","ieee_address":"0x00124b000ff0335b"},"type":"device_announce"}'

I believe Device 'bedroom/switch' announced itself means that the switch just restarted itself.

While the device is restarting, it is unresponsive for 4-5 seconds.

This is the config:

image

image

Any idea what could be causing that?

ptvoinfo commented 4 months ago

@Flavien Hi. Did you test it with the constant power supply or using a battery? Sometimes, long activity of a device (several clicks) may temporarily decrease battery voltage lower than 2.2V and the device reboots.

Flavien commented 4 months ago

I am using two AAA alkaline batteries. I haven't manage to reproduce this on constant power supply. Do you think it would be more stable using AAA lithium batteries instead?

ptvoinfo commented 4 months ago

Try to add a tantalum capacitor of 220 mf in parallel with your battery. I may help to smooth the wake-up phase.

Flavien commented 4 months ago

Thank you for the advice, I will get some capacitors and try it.

Also, I am not sure if this is related but I'm also seeing lots of errors like Data confirm error and 'No network route' (205) from the PSM device:

zigbee2mqtt  | 2024-07-14T09:34:03.726 debug:   zh:zstack: Wait 2000ms
zigbee2mqtt  | 2024-07-14T09:34:05.729 debug:   zh:zstack: sendZclFrameToEndpointInternal 0x00124b000ff0335b:4261/3 (0,4,2)
zigbee2mqtt  | 2024-07-14T09:34:05.733 debug:   zh:zstack:znp: SREQ: --> AF - dataRequest - {"dstaddr":4261,"destendpoint":3,"srcendpoint":1,"clusterid":18,"transid":76,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[24,226,11,10,0]}}
zigbee2mqtt  | 2024-07-14T09:34:05.733 debug:   zh:zstack:unpi:writer: --> frame [254,15,36,1,165,16,3,1,18,0,76,0,30,5,24,226,11,10,0,35]
zigbee2mqtt  | 2024-07-14T09:34:05.735 debug:   zh:zstack:unpi:parser: <-- [254,1,100,1,0,100]
zigbee2mqtt  | 2024-07-14T09:34:05.735 debug:   zh:zstack:unpi:parser: --- parseNext [254,1,100,1,0,100]
zigbee2mqtt  | 2024-07-14T09:34:05.736 debug:   zh:zstack:unpi:parser: --> parsed 1 - 3 - 4 - 1 - [0] - 100
zigbee2mqtt  | 2024-07-14T09:34:05.736 debug:   zh:zstack:znp: SRSP: <-- AF - dataRequest - {"status":0}
zigbee2mqtt  | 2024-07-14T09:34:05.736 debug:   zh:zstack:unpi:parser: --- parseNext []
zigbee2mqtt  | 2024-07-14T09:34:07.352 debug:   zh:zstack:unpi:parser: <-- [254,3,68,128,205,1,76,71]
zigbee2mqtt  | 2024-07-14T09:34:07.352 debug:   zh:zstack:unpi:parser: --- parseNext [254,3,68,128,205,1,76,71]
zigbee2mqtt  | 2024-07-14T09:34:07.352 debug:   zh:zstack:unpi:parser: --> parsed 3 - 2 - 4 - 128 - [205,1,76] - 71
zigbee2mqtt  | 2024-07-14T09:34:07.352 debug:   zh:zstack:znp: AREQ: <-- AF - dataConfirm - {"status":205,"endpoint":1,"transid":76}
zigbee2mqtt  | 2024-07-14T09:34:07.352 debug:   zh:zstack:unpi:parser: --- parseNext []
zigbee2mqtt  | 2024-07-14T09:34:07.352 debug:   zh:zstack: Data confirm error (0x00124b000ff0335b:4261,205,4)
zigbee2mqtt  | 2024-07-14T09:34:07.353 debug:   zh:zstack: sendZclFrameToEndpointInternal 0x00124b000ff0335b:4261/3 (0,0,1)
zigbee2mqtt  | 2024-07-14T09:34:07.353 debug:   zh:zstack:znp: SREQ: --> AF - dataRequest - {"dstaddr":4261,"destendpoint":3,"srcendpoint":1,"clusterid":18,"transid":77,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[24,227,11,10,0]}}
zigbee2mqtt  | 2024-07-14T09:34:07.353 debug:   zh:zstack:unpi:writer: --> frame [254,15,36,1,165,16,3,1,18,0,77,0,30,5,24,227,11,10,0,35]
zigbee2mqtt  | 2024-07-14T09:34:07.355 debug:   zh:controller:endpoint: ZCL command 0x00124b000ff0335b/3 genMultistateInput.defaultRsp({"cmdId":10,"statusCode":0}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":226,"writeUndiv":false}) failed (Data request failed with error: 'No network route' (205))
zigbee2mqtt  | 2024-07-14T09:34:07.355 debug:   zh:controller:device: Default response to 0x00124b000ff0335b failed
zigbee2mqtt  | 2024-07-14T09:34:07.369 debug:   zh:zstack:unpi:parser: <-- [254,1,100,1,0,100]
zigbee2mqtt  | 2024-07-14T09:34:07.369 debug:   zh:zstack:unpi:parser: --- parseNext [254,1,100,1,0,100]
zigbee2mqtt  | 2024-07-14T09:34:07.369 debug:   zh:zstack:unpi:parser: --> parsed 1 - 3 - 4 - 1 - [0] - 100
zigbee2mqtt  | 2024-07-14T09:34:07.370 debug:   zh:zstack:znp: SRSP: <-- AF - dataRequest - {"status":0}
zigbee2mqtt  | 2024-07-14T09:34:07.370 debug:   zh:zstack:unpi:parser: --- parseNext []
zigbee2mqtt  | 2024-07-14T09:34:08.901 debug:   zh:zstack:unpi:parser: <-- [254,3,68,128,205,1,77,70]
zigbee2mqtt  | 2024-07-14T09:34:08.901 debug:   zh:zstack:unpi:parser: --- parseNext [254,3,68,128,205,1,77,70]
zigbee2mqtt  | 2024-07-14T09:34:08.902 debug:   zh:zstack:unpi:parser: --> parsed 3 - 2 - 4 - 128 - [205,1,77] - 70
zigbee2mqtt  | 2024-07-14T09:34:08.902 debug:   zh:zstack:znp: AREQ: <-- AF - dataConfirm - {"status":205,"endpoint":1,"transid":77}
zigbee2mqtt  | 2024-07-14T09:34:08.902 debug:   zh:zstack:unpi:parser: --- parseNext []
zigbee2mqtt  | 2024-07-14T09:34:08.903 debug:   zh:zstack: Data confirm error (0x00124b000ff0335b:4261,205,0)
zigbee2mqtt  | 2024-07-14T09:34:08.903 debug:   zh:zstack: Wait 2000ms
zigbee2mqtt  | 2024-07-14T09:34:10.905 debug:   zh:zstack: sendZclFrameToEndpointInternal 0x00124b000ff0335b:4261/3 (0,1,1)

This seem to sometimes cause delayed responses. Why is it happening and how to prevent it?

ptvoinfo commented 4 months ago

@Flavien The PSM device cannot receive commands when it sleeps (radio is turned off).

Flavien commented 4 months ago

Thanks, that's what I thought. This happens after pressing the button, so would that be resolved by enabling "Wait for commands after a report in PSM"?

Flavien commented 1 month ago

After spending more time looking into this, I don't believe this is caused by the voltage drop, this looks more like a bug in the PSM firmware @ptvoinfo .

I've monitored the voltage during the wake up phase (using new batteries). The voltage does drop a little bit, but stays above 3.1V at all times, so that should not cause the device to reset (yet it does).

Any idea what could be happening, or how we could get more debug information to find out?