search

h2zero / esp-nimble-cpp

C++ library for the esp32 NimBLE stack based on and mostly compatible with @nkolban cpp_utils BLE library.
https://h2zero.github.io/esp-nimble-cpp/
Apache License 2.0
176 stars 61 forks source link

Two successive calls to write-with-response cause fatal error when NimBLE is handling the write acknowledgement(s) #115

Open Berg0162 opened 1 year ago

Berg0162 commented 1 year ago

When the client calls pRemoteCharacteristic->writeValue(ftmcpData, true), write-with-response, it takes some time (about 300-400ms?) before the server has acknowledged the write action.... However, if within that time period a second call to pRemoteCharacteristic->writeValue(ftmcpData, true) is executed, that second call is handled correctly at first, but the acknowledgement by the server of the write action is later causing a fatal error!

Have a look at the critical part of the log file (it is about the Char with UUID 0x2AD9):

16:39:01.289 -> D NimBLEServer: >> handleGapEvent: 16:39:01.289 -> D NimBLECharacteristicCallbacks: onStatus: default

16:39:01.289 -> D NimBLECharacteristic: Characteristic 0x2ad9 Write event 16:39:01.289 -> D NimBLECharacteristic: >> setValue: length=1, data=01, characteristic UUID=0x2ad9 16:39:01.289 -> D NimBLECharacteristic: << setValue 16:39:01.289 -> >> CPWrite 16:39:01.289 -> << CPWrite 16:39:01.289 -> D NimBLERemoteCharacteristic: >> writeValue(), length: 1 16:39:01.334 -> --> Raw FTM Control Point Data [len: 1] [OpCode: 01] [Values: 00 ] 16:39:01.334 -> Reset Machine! 16:39:01.334 -> D NimBLECharacteristicCallbacks: onWrite: default

16:39:01.409 -> D NimBLECharacteristic: Characteristic 0x2ad9 Write event 16:39:01.409 -> D NimBLECharacteristic: >> setValue: length=1, data=00, characteristic UUID=0x2ad9 16:39:01.409 -> D NimBLECharacteristic: << setValue 16:39:01.409 -> >> CPWrite 16:39:01.409 -> << CPWrite 16:39:01.409 -> D NimBLERemoteCharacteristic: >> writeValue(), length: 1 16:39:01.409 -> --> Raw FTM Control Point Data [len: 1] [OpCode: 00] [Values: 00 ] 16:39:01.444 -> Request Control of Machine! 16:39:01.444 -> D NimBLECharacteristicCallbacks: onWrite: default

16:39:01.570 -> D NimBLEClient: Got Client event 16:39:01.570 -> D NimBLEClient: Notify Recieved for handle: 16 16:39:01.570 -> D NimBLEClient: checking service 0x180a for handle: 16 16:39:01.604 -> D NimBLEClient: checking service 0x1818 for handle: 16 16:39:01.604 -> D NimBLEClient: checking service 0x1816 for handle: 16 16:39:01.604 -> D NimBLEClient: checking service 0x1826 for handle: 16 16:39:01.604 -> D NimBLEClient: Got Notification for characteristic Characteristic: uuid: 0x2ad2, handle: 16 0x0010, props: 0x10 16:39:01.604 -> Descriptor: uuid: 0x2902, handle: 17 16:39:01.604 -> D NimBLEClient: Invoking callback for notification on characteristic Characteristic: uuid: 0x2ad2, handle: 16 0x0010, props: 0x10 16:39:01.637 -> Descriptor: uuid: 0x2902, handle: 17 16:39:01.637 -> D NimBLECharacteristic: >> setValue: length=11, data=6402000000001400000000, characteristic UUID=0x2ad2 16:39:01.637 -> D NimBLECharacteristic: << setValue 16:39:01.637 -> D NimBLECharacteristic: >> notify: length: 11 16:39:01.637 -> D NimBLECharacteristicCallbacks: onNotify: default

16:39:01.637 -> D NimBLEServer: >> handleGapEvent: 16:39:01.670 -> D NimBLECharacteristicCallbacks: onStatus: default 16:39:01.670 -> D NimBLECharacteristic: << notify

16:39:01.670 -> D NimBLEClient: Got Client event 16:39:01.670 -> D NimBLEClient: Notify Recieved for handle: 43 16:39:01.670 -> D NimBLEClient: checking service 0x180a for handle: 43 16:39:01.670 -> D NimBLEClient: checking service 0x1818 for handle: 43 16:39:01.670 -> D NimBLEClient: Got Notification for characteristic Characteristic: uuid: 0x2a63, handle: 43 0x002b, props: 0x10 16:39:01.704 -> Descriptor: uuid: 0x2902, handle: 44 16:39:01.704 -> D NimBLEClient: Invoking callback for notification on characteristic Characteristic: uuid: 0x2a63, handle: 43 0x002b, props: 0x10 16:39:01.704 -> Descriptor: uuid: 0x2902, handle: 44 16:39:01.704 -> D NimBLECharacteristic: >> setValue: length=4, data=00000000, characteristic UUID=0x2a63 16:39:01.704 -> D NimBLECharacteristic: << setValue 16:39:01.704 -> D NimBLECharacteristic: >> notify: length: 4 16:39:01.737 -> D NimBLECharacteristicCallbacks: onNotify: default

16:39:01.737 -> D NimBLEServer: >> handleGapEvent: 16:39:01.737 -> D NimBLECharacteristicCallbacks: onStatus: default 16:39:01.737 -> D NimBLECharacteristic: << notify

16:39:01.737 -> I NimBLERemoteCharacteristic: Write complete; status=0 conn_handle=0 16:39:01.737 -> D NimBLERemoteCharacteristic: << writeValue, rc: 0

16:39:01.737 -> Guru Meditation Error: Core 1 panic'ed (IllegalInstruction). Exception was unhandled. 16:39:01.770 -> Memory dump at 0x400d2628: 5ee508a8 00f01dc3 81004136 16:39:01.770 -> Core 1 register dump: 16:39:01.770 -> PC : 0x400d262d PS : 0x00060030 A0 : 0x00000000 A1 : 0x3ffd0cf0
16:39:01.770 -> A2 : 0x00000000 A3 : 0x00000000 A4 : 0x00000000 A5 : 0x00000000
16:39:01.770 -> A6 : 0x00000000 A7 : 0x00000000 A8 : 0x800d262d A9 : 0x3ffd0cd0
16:39:01.770 -> A10 : 0x3ffd1f04 A11 : 0x00000001 A12 : 0x0000000a A13 : 0x3ffd0d8c
16:39:01.802 -> A14 : 0x00000000 A15 : 0x3ffc3d84 SAR : 0x00000004 EXCCAUSE: 0x00000000
16:39:01.802 -> EXCVADDR: 0x00000000 LBEG : 0x40091b11 LEND : 0x40091b21 LCOUNT : 0xfffffff9

h2zero commented 4 months ago

This doesn't look like an error in the library, the crash happens after the write is complete and returns to the caller.

h2zero commented 4 months ago

@Berg0162 are you still experiencing this?

Berg0162 commented 4 months ago

I have worked around it. Placed write-with-response in a FreeRtos task and check the task is finished before to call it again...