Skip to content

BLE server notify() sent before onWrite() client ack in 3.3.0+ (Nimble v. Bluedroid difference) #11938

@MagnmCI

Description

@MagnmCI

Board

esp32-c6-devkitC, esp32-s3-zero

Device Description

DevkitC powered over usbc via jtag connector. S3-zero powered over usbc connector.

Hardware Configuration

Nothing else attached

Version

v3.3.2

Type

Bug

IDE Name

Arduino IDE

Operating System

MacOS 26.0.1

Flash frequency

QIO 80Mhz

PSRAM enabled

no

Upload speed

115200

Description

The attached sketch is a minimalist BLE server, when compiled against v3.2.1 (Bluedroid default), the server receives a write to initiate a client handshake, server acknowledges write and then notifies the client with a success message to complete the handshake. But when compiled against v3.3.2 (Nimble default), the notify happens before the write acknowledge and this causes the client handshake to fail because the notify-response timestamp is earlier than (or the same as) the write-request timestamp.

Note: I am calling notify() from the onWrite() callback which is possibly not a good practice given the call chain, but this code worked fine for the client when compiled with Bluedroid but failed silently when compilied with Nimble. For anyone being migrated from Bluedroid to Nimble via esp32 arduino core, this lack of backwards compatibility wastes a lot of time (as it did mine).

At issue here is that Bluedroid write acknowldge/notify timing is different from Nimble. I should get a warning that calling notify() from within onWrite() is not a good idea, or the timing of how this is handled should be the same as Bluedroid. Possibly both.

Sketch

#include <BLEDevice.h>
#include <BLE2902.h>

BLEServer* pServer = nullptr;
BLECharacteristic* pTxCharacteristic = nullptr;
BLECharacteristic* pRxCharacteristic = nullptr;

class MyServerCallbacks : public BLEServerCallbacks {
  /* esp32 v3.3.0 Nimble format */
  // void onConnect(BLEServer* pServer, ble_gap_conn_desc *param) override {
  //   pServer->updateConnParams(param->conn_handle, 12, 24, 4, 500);
  // }
  /* esp32 v3.2.1 Bluedroid format */
  void onConnect(BLEServer* pServer, esp_ble_gatts_cb_param_t *param) override {
    pServer->updateConnParams(param->connect.remote_bda, 12, 24, 4, 500);
  }
  void onDisconnect(BLEServer* pServer) override {
    pServer->getAdvertising()->start();
  }
};

class MyCallbacks : public BLECharacteristicCallbacks {
  void onWrite(BLECharacteristic* pCharacteristic) override {
    String rxValue = String(pCharacteristic->getValue().c_str());
    Serial.print("BLE Write: "); Serial.println(rxValue);
    if (rxValue == "CHAN;2100\n") {
      pTxCharacteristic->setValue("# Active channels set to 2100\n");
      pTxCharacteristic->notify();
    } else {
      pTxCharacteristic->setValue("0,0,0,0,0\n");
      pTxCharacteristic->notify();
    }
  }
};

void setup() {
  Serial.begin(115200);

  BLEDevice::init("ESP32_Skycommand_BLE");

  pServer = BLEDevice::createServer();
  pServer->setCallbacks(new MyServerCallbacks());

  BLEService* pService = pServer->createService("6e400001-b5a3-f393-e0a9-e50e24dcca9e");

  pTxCharacteristic = pService->createCharacteristic("6e400003-b5a3-f393-e0a9-e50e24dcca9e",
        BLECharacteristic::PROPERTY_NOTIFY | BLECharacteristic::PROPERTY_READ
    );
  pTxCharacteristic->addDescriptor(new BLE2902());

  pRxCharacteristic = pService->createCharacteristic("6e400002-b5a3-f393-e0a9-e50e24dcca9e",
        BLECharacteristic::PROPERTY_WRITE | BLECharacteristic::PROPERTY_WRITE_NR
    );
  pRxCharacteristic->setCallbacks(new MyCallbacks());
  pService->start();

  BLEAdvertising* pAdvertising = pServer->getAdvertising();
  pAdvertising->start();
}

void loop() {
  // callbacks do all the work
}

Debug Message

Following are detailed logs from the Android app nRF Connect from Nordic Semi
-----------------------------------------------------------------------
nRF Connect (magnmci: Nimble v3.3.2), 2025-10-22
ESP32_Skycommand_BLE (F0:F5:BD:02:A8:9A)
V	09:21:19.688	Connecting to F0:F5:BD:02:A8:9A...
D	09:21:19.688	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	09:21:19.816	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	09:21:19.816	Connected to F0:F5:BD:02:A8:9A
V	09:21:19.834	Discovering services...
D	09:21:19.834	gatt.discoverServices()
D	09:21:19.835	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
I	09:21:19.996	Connection parameters updated (interval: 30.0ms, latency: 4, timeout: 5000ms)
I	09:21:20.526	Connection parameters updated (interval: 20.0ms, latency: 0, timeout: 5000ms)
D	09:21:20.832	[Callback] Services discovered with status: 0
I	09:21:20.832	Services discovered
V	09:21:20.838	Generic Access (0x1800)
- Device Name [R] (0x2A00)
- Appearance [R] (0x2A01)
Generic Attribute (0x1801)
- Service Changed [I] (0x2A05)
   Client Characteristic Configuration (0x2902)
- Server Supported Features [R] (0x2B3A)
- Client Supported Features [R W] (0x2B29)
Nordic UART Service (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
- TX Characteristic [N R] (6e400003-b5a3-f393-e0a9-e50e24dcca9e)
   Client Characteristic Configuration (0x2902)
- RX Characteristic [W WNR] (6e400002-b5a3-f393-e0a9-e50e24dcca9e)
D	09:21:20.838	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
D	09:21:20.842	gatt.setCharacteristicNotification(6e400003-b5a3-f393-e0a9-e50e24dcca9e, true)
I	09:21:21.047	Connection parameters updated (interval: 30.0ms, latency: 4, timeout: 5000ms)
V	09:21:23.862	Enabling notifications for 6e400003-b5a3-f393-e0a9-e50e24dcca9e
D	09:21:23.862	gatt.setCharacteristicNotification(6e400003-b5a3-f393-e0a9-e50e24dcca9e, true)
D	09:21:23.863	gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x0100)
I	09:21:23.925	Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
A	09:21:23.925	"Notifications enabled" sent
V	09:21:23.928	Notifications enabled for 6e400003-b5a3-f393-e0a9-e50e24dcca9e
V	09:21:41.149	Writing request to characteristic 6e400002-b5a3-f393-e0a9-e50e24dcca9e
D	09:21:41.149	gatt.writeCharacteristic(6e400002-b5a3-f393-e0a9-e50e24dcca9e, value=0x4348414E3B32313030)
I	09:21:41.236	Notification received from 6e400003-b5a3-f393-e0a9-e50e24dcca9e, value: (0x) 23-20-41-63-74-69-76-65-20-63-68-61-6E-6E-65-6C-73-20-73-65, "# Active channels se"
A	09:21:41.236	"# Active channels se" received
I	09:21:41.236	Data written to 6e400002-b5a3-f393-e0a9-e50e24dcca9e, value: (0x) 43-48-41-4E-3B-32-31-30-30, "CHAN;2100"
A	09:21:41.237	"CHAN;2100" sent
[ magnmci: note the write acknowledge occurs AFTER the notification is sent ]
----------------------------------------------------------
nRF Connect (magnmci: Bluedroid v3.2.1), 2025-10-22
ESP32_Skycommand_BLE (F0:F5:BD:02:A8:9A)
V	09:29:41.770	Connecting to F0:F5:BD:02:A8:9A...
D	09:29:41.770	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	09:29:41.975	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	09:29:41.975	Connected to F0:F5:BD:02:A8:9A
D	09:29:41.975	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
V	09:29:41.976	Discovering services...
D	09:29:41.976	gatt.discoverServices()
I	09:29:42.144	Connection parameters updated (interval: 30.0ms, latency: 4, timeout: 5000ms)
I	09:29:42.580	Connection parameters updated (interval: 20.0ms, latency: 0, timeout: 5000ms)
D	09:29:42.984	[Callback] Services discovered with status: 0
I	09:29:42.985	Services discovered
V	09:29:42.993	Generic Attribute (0x1801)
- Service Changed [I] (0x2A05)
   Client Characteristic Configuration (0x2902)
Generic Access (0x1800)
- Device Name [R] (0x2A00)
- Appearance [R] (0x2A01)
- Central Address Resolution [R] (0x2AA6)
Nordic UART Service (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
- TX Characteristic [N R] (6e400003-b5a3-f393-e0a9-e50e24dcca9e)
   Client Characteristic Configuration (0x2902)
- RX Characteristic [W WNR] (6e400002-b5a3-f393-e0a9-e50e24dcca9e)
D	09:29:42.993	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
D	09:29:42.997	gatt.setCharacteristicNotification(6e400003-b5a3-f393-e0a9-e50e24dcca9e, true)
I	09:29:43.198	Connection parameters updated (interval: 30.0ms, latency: 4, timeout: 5000ms)
V	09:29:45.558	Enabling notifications for 6e400003-b5a3-f393-e0a9-e50e24dcca9e
D	09:29:45.558	gatt.setCharacteristicNotification(6e400003-b5a3-f393-e0a9-e50e24dcca9e, true)
D	09:29:45.560	gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x0100)
I	09:29:45.627	Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
A	09:29:45.627	"Notifications enabled" sent
V	09:29:45.632	Notifications enabled for 6e400003-b5a3-f393-e0a9-e50e24dcca9e
V	09:29:55.329	Writing request to characteristic 6e400002-b5a3-f393-e0a9-e50e24dcca9e
D	09:29:55.329	gatt.writeCharacteristic(6e400002-b5a3-f393-e0a9-e50e24dcca9e, value=0x4348414E3B32313030)
I	09:29:55.439	Data written to 6e400002-b5a3-f393-e0a9-e50e24dcca9e, value: (0x) 43-48-41-4E-3B-32-31-30-30, "CHAN;2100"
A	09:29:55.439	"CHAN;2100" sent
I	09:29:55.442	Notification received from 6e400003-b5a3-f393-e0a9-e50e24dcca9e, value: (0x) 23-20-41-63-74-69-76-65-20-63-68-61-6E-6E-65-6C-73-20-73-65, "# Active channels se"
A	09:29:55.442	"# Active channels se" received
[magnmci: note the write acknowledge occurs before the notification is sent]

Other Steps to Reproduce

You can see the timing differences using nRF Connect for Android - logs included in debug. The timing issue can be seen in the last 5 lines of each.

I have checked existing issues, online documentation and the Troubleshooting Guide

  • I confirm I have checked existing issues, online documentation and Troubleshooting guide.

Metadata

Metadata

Assignees

Labels

Type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions