mynewt-nimble icon indicating copy to clipboard operation
mynewt-nimble copied to clipboard

Callback triggered multiple times for same request

Open HendrikVE opened this issue 7 years ago • 6 comments

Hello,

I have an issue with nimble on RIOT. My testing environment is the following:

  • nrf52dk
  • latest RIOT master https://github.com/RIOT-OS/RIOT/commit/c0d907addc26450cae4de645711ecfac0fa85e1e (but problem is there for several weeks already)
  • RIOT example application 'nimble_gatt'
  • Nordics nrF Connect App (but also with my own one)

If I read the read- and writeable characteristic, then its callback is called twice, the readonly characteristic only once. But if i write to the rw characteristic and read it again, the callback is called once from there on. In another application a callback is called 6 times on a read operation, which leads to empty messages if I don't handle every single callback, but that's problematic because it's a ringbuffer and I get the message exactly one time.

@haukepetersen experienced the same issue on his board with the nimble_gatt example.

Is that behaviour intended? I thought as a callback it should be only called once, when the characteristic is read from or wrote to, or am I wrong?

Below is my terminal output:

2019-03-23 17:23:19,013 - INFO # main(): This is RIOT! (Version: 2019.04-devel-597-gc0d90)
2019-03-23 17:23:19,015 - INFO # NimBLE GATT Server Example

2019-03-23 17:24:30,496 - INFO # service 'rw demo' callback triggered
2019-03-23 17:24:30,499 - INFO # access to characteristic 'rw demo (write)'
2019-03-23 17:24:30,501 - INFO # read from characteristic
2019-03-23 17:24:30,508 - INFO # current value of rm_demo_write_data: 'This characteristic is read- and writeable!'
2019-03-23 17:24:30,509 - INFO # 
2019-03-23 17:24:30,642 - INFO # service 'rw demo' callback triggered
2019-03-23 17:24:30,646 - INFO # access to characteristic 'rw demo (write)'
2019-03-23 17:24:30,648 - INFO # read from characteristic
2019-03-23 17:24:30,655 - INFO # current value of rm_demo_write_data: 'This characteristic is read- and writeable!'
2019-03-23 17:24:30,655 - INFO # 

2019-03-23 17:24:34,395 - INFO # service 'rw demo' callback triggered
2019-03-23 17:24:34,399 - INFO # access to characteristic 'rw demo (read-only)'
2019-03-23 17:24:34,401 - INFO # new random number: 8
2019-03-23 17:24:34,402 - INFO # 

2019-03-23 17:24:45,657 - INFO # service 'rw demo' callback triggered
2019-03-23 17:24:45,660 - INFO # access to characteristic 'rw demo (write)'
2019-03-23 17:24:45,662 - INFO # write to characteristic
2019-03-23 17:24:45,669 - INFO # old value of rm_demo_write_data: 'This characteristic is read- and writeable!'
2019-03-23 17:24:45,673 - INFO # new value of rm_demo_write_data: 'test'
2019-03-23 17:24:45,674 - INFO # 

2019-03-23 17:24:48,192 - INFO # service 'rw demo' callback triggered
2019-03-23 17:24:48,195 - INFO # access to characteristic 'rw demo (write)'
2019-03-23 17:24:48,198 - INFO # read from characteristic
2019-03-23 17:24:48,201 - INFO # current value of rm_demo_write_data: 'test'
2019-03-23 17:24:48,202 - INFO #

HendrikVE avatar Mar 23 '19 16:03 HendrikVE

Hi,we just released NimBLE 1.1.0, could you check if this is stil an issue?

sjanc avatar Apr 10 '19 11:04 sjanc

Hello,

I've tested it again and edited the file "pkg/nimble/Makefile" in the RIOT repository. I've set the PKG_VERSION to the latest commit of nimble (18afa6b76c12607b4cf45fa922c1c77c9163c8eb), but I still get multiple calls on my callbacks.

HendrikVE avatar Apr 18 '19 09:04 HendrikVE

Is this issues still valid? I have just looked quickly into the code and I don't see a way that access callback would be triggered twice. Would you mind sending btsnoop logs matching those terminal logs?

rymanluk avatar May 14 '19 21:05 rymanluk

Yes, sadly I still have this issue. Here you go: hci_snoop20190516161721.cfa.zip

HendrikVE avatar May 16 '19 14:05 HendrikVE

Hi,

yes, this is how GATT defines procedure for long reads (when data is larger than current ATT MTU), as NimBLE hides some details of long reads on server side it appears as multiple read callbacks, some more discussion on this (and how we could extend API to give application more context) is in https://github.com/apache/mynewt-nimble/issues/1090

sjanc avatar Feb 01 '24 09:02 sjanc