Sleepy end device causing missed report of variable change

[Isaia F]

Greetings, i'm developing a custom sleepy end device whose role is to detect whether a certain event is occurring, this triggers the update (EDIT: via interrupt handler) of a custom cluster boolean attribute that is then reported to the coordinator, once the event stops being detected, the boolean attribute is then reset by means of a Zephyr timer.

I have noticed that, with the sleepy end device behavior configured, sometimes the device fails to report the change from "false" to "true", but then reports correctly the change back to false when the timer expires.

A check with a packet sniffer further confirmed the fact that the packet is simply not being sent.

How can i solve this issue?
Thanks in advance

EDIT: addendum
After setting up the project to log to RTT and checking more with a DK running the Shell sample as coordinator, i see the following:
-the sending of the report packet seems delayed by around 2-4 seconds (tested by counting the time between a led turning off, signaling the update of the attribute to false and the reception of the report)
-the RTT does not seem to grab all logs in a timely manner, sometimes losing or receiving LOG_INF in a delayed manner, i do not know if this is related

[Isaia F]

After convening with my colleagues there appears to be no need to make the ticket private. 
I'm uploading a tar archive containing a version of the project that works in the dk.
Do note the following:
1) The modifications from the original source are all in main.c, a text search for the __TEST__ string will highlight the modifications done
2) The trigger handler has been slaved to the buttons_changed function, we hope it will still work in interrupt context
3) As much as we would have liked to test this version of the firmware to see if the issue repeats even with such modifications, we find ourselves unable to as SES has managed to brick the nrf52840dk board we were planning on using as a coordinator, thing for which we'll open a new ticket, and we're leery of risking more as of right now.
archive.tgz

[Isaia F]

Addendum: the ncs-updates folder contains a few additions to the ncs folder, namely to handles the lis2dw12 and the connection reset button ( i can't edit my post because the button won't show on neither chrome or firefox)


Addendum to the addendum: we managed to flash a coordinator on a nrf52833dk and configured our end device in the following ways for testing (same project as we sent in the tgz)

When configured as End Device (not Sleepy) it behaved even worse when it came to sending the report frames false->true
In Router Mode however it behaved as expected (reliably sending the reporting frame every change in the parameter), unfortunately the consumption in router mode is far too high for our purposes.

[Marte Myrvold]

Hi,

How is the device sending the attribute to the coordinator? Does the coordinator subscribe to attribute reports on value change, or is there something else triggering the attribute report? I could not find anything regarding this in the project code. I am testing the project and it prints that is_shaked is changed to 1 and back to 0 again, but no packets are sent from the device.

Best regards,

Marte

[Isaia F]

Hi, 

The device should update the variable, and it's configured in the custom cluster as a reportable attribute

To test we used a DK with the Shell sample and configured the reporting.

Below is an example of what we inputted in the shell terminal to configure the reporting. So i suppose the answer is "the coordinator subscribes to the attribute".

uart:~$ zdo mgmt_lqi 0000
[idx] ext_pan_id ext_addr short_addr flags permit_join depth lqi
[ 0] f4ce36bc41dcdf74 f4ce364145c4c951 0x2541 0x15 0 1 172
ZDO request 1 complete
Done
uart:~$ zdo bind on f4ce364145c4c951 10 f4ce36bc41dcdf74 64 0xabcd 0x2541
Done
uart:~$ zcl subscribe on 0x2541 10 0xabcd 0x0104 0x0001 16

[Marte Myrvold]

Hi,

Thank you for clarifying. 

I used this command when testing, but at first it looked like the device only reported periodically. I see now that it reports both periodically and when the value is changed.

I believe I managed to reproduce the issue. Sometimes it did not send true even if I had pressed the button and saw in the log that it was changed. At least on my side the issue seemed to be that the attribute changed back again to false so quickly that the change happened before the attribute was sent, causing only false to be sent. When I added a small timer, k_sleep(K_MSEC(100)), before changing the attribute back to false then I did not see the issue anymore. Does it sound like this might be the reason for the problem on your side as well? I added the timer just after checking if is_shaked is true and before setting it to false with ZB_ZCL_SET_ATTRIBUTE.

Best regards,

Marte