I'm trying to create a cycling power service on the ESP32 using PlatformIO and the NimBLE-Arduino library.
Connecting, bonding, subscribing to the notifications and receiving the power data all work when the client is the nRF Connect Android app, but my Lezyne GPS Mini cyclocomputer is not able to complete the pairing process. I'm looking for a way to decypher the logs and understand the problem in the communication.
My code, reduced to to the minimum:
#include <Arduino.h>
#include <NimBLEDevice.h>
#define CYCLING_POWER_SERVICE_UUID ((uint16_t) 0x1818)
#define CYCLING_POWER_FEATURE_CHAR_UUID ((uint16_t) 0x2A65)
#define SENSOR_LOCATION_CHAR_UUID ((uint16_t) 0x2A5D)
#define SENSOR_LOCATION_RIGHT_CRANK ((uint8_t) 6)
#define CYCLING_POWER_MEASUREMENT_CHAR_UUID ((uint16_t) 0x2A63)
class BLE : public BLEServerCallbacks {
public:
BLEServer *server;
BLECharacteristic *measurementCharacteristic;
bool connected = false;
bool oldConnected = false;
short power = 0;
unsigned short revolutions = 0;
unsigned short timestamp = 0;
const unsigned short flags = 0x20; // TODO
unsigned char bufMeasurent[8];
unsigned char bufSensorLocation[1];
unsigned char bufControlPoint[1];
unsigned char bufFeature[4];
void setup() {
BLEDevice::init("PM");
server = BLEDevice::createServer();
server->setCallbacks(this);
BLEUUID serviceUUID = BLEUUID(CYCLING_POWER_SERVICE_UUID);
BLEService *service = server->createService(serviceUUID);
BLECharacteristic *featureCharasteristic = service->createCharacteristic(
BLEUUID(CYCLING_POWER_FEATURE_CHAR_UUID),
NIMBLE_PROPERTY::READ
);
bufFeature[0] = 0xff;
bufFeature[1] = 0xff;
bufFeature[2] = 0xff;
bufFeature[3] = 0xff; // TODO
featureCharasteristic->setValue((uint8_t *)&bufFeature, 4);
BLECharacteristic *sensorLocationCharasteristic = service->createCharacteristic(
BLEUUID(SENSOR_LOCATION_CHAR_UUID),
NIMBLE_PROPERTY::READ
);
bufSensorLocation[0] = SENSOR_LOCATION_RIGHT_CRANK & 0xff;
sensorLocationCharasteristic->setValue((uint8_t *)bufSensorLocation, 1);
measurementCharacteristic = service->createCharacteristic(
BLEUUID(CYCLING_POWER_MEASUREMENT_CHAR_UUID),
NIMBLE_PROPERTY::READ
| NIMBLE_PROPERTY::NOTIFY
| NIMBLE_PROPERTY::INDICATE
);
service->start();
BLEAdvertising *advertising = BLEDevice::getAdvertising();
advertising->addServiceUUID(serviceUUID);
BLEDevice::startAdvertising();
}
void loop() {
// notify changed value
if (connected) {
bufMeasurent[0] = flags & 0xff;
bufMeasurent[1] = (flags >> 8) & 0xff;
bufMeasurent[2] = power & 0xff;
bufMeasurent[3] = (power >> 8) & 0xff;
bufMeasurent[4] = revolutions & 0xff;
bufMeasurent[5] = (revolutions >> 8) & 0xff;
bufMeasurent[6] = timestamp & 0xff;
bufMeasurent[7] = (timestamp >> 8) & 0xff;
measurementCharacteristic->setValue((uint8_t *)&bufMeasurent, 8);
measurementCharacteristic->notify();
delay(1000);
}
// disconnecting
if (!connected && oldConnected) {
delay(500);
server->startAdvertising();
Serial.println("start advertising");
oldConnected = connected;
}
// connecting
if (connected && !oldConnected) {
oldConnected = connected;
}
}
void onConnect(BLEServer *pServer, ble_gap_conn_desc* desc) {
connected = true;
Serial.println("Server onConnect");
}
void onDisconnect(BLEServer *pServer) {
connected = false;
Serial.println("Server onDisconnect");
}
};
BLE ble;
void setup() {
Serial.begin(115200);
ble.setup();
}
void loop() {
if (ble.connected) {
ble.power = random(300);
ble.revolutions = random(2);
ble.timestamp = (ushort)millis();
delay(100);
}
ble.loop();
}
Logs with NimBLE debug log enabled:
entry 0x400806a8
ble_hs_hci_cmd_send: ogf=0x03 ocf=0x0003 len=0
0x03 0x0c 0x00
ble_hs_hci_cmd_send: ogf=0x04 ocf=0x0001 len=0
0x01 0x10 0x00
ble_hs_hci_cmd_send: ogf=0x04 ocf=0x0003 len=0
0x03 0x10 0x00
ble_hs_hci_cmd_send: ogf=0x03 ocf=0x0001 len=8
0x01 0x0c 0x08 0x90 0x80 0x00 0x02 0x00 0x80 0x00 0x20
ble_hs_hci_cmd_send: ogf=0x03 ocf=0x0063 len=8
0x63 0x0c 0x08 0x00 0x00 0x80 0x00 0x00 0x00 0x00 0x00
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0001 len=8
0x01 0x20 0x08 0x7f 0x06 0x00 0x00 0x00 0x00 0x00 0x00
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0002 len=0
0x02 0x20 0x00
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0003 len=0
0x03 0x20 0x00
ble_hs_hci_cmd_send: ogf=0x04 ocf=0x0009 len=0
0x09 0x10 0x00
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0018 len=0
0x18 0x20 0x00
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0018 len=0
0x18 0x20 0x00
Device added to RL, Resolving list count = 1
ble_hs_hci_cmd_send: ogf=0x03 ocf=0x0031 len=1
0x31 0x0c 0x01 0x01
ble_hs_hci_cmd_send: ogf=0x03 ocf=0x0033 len=7
0x33 0x0c 0x07 0xff 0x00 0x00 0x0c 0x00 0x00 0x00
ble_hs_hci_cmd_send: ogf=0x03 ocf=0x0031 len=1
0x31 0x0c 0x01 0x00
looking up peer sec;
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0018 len=0
0x18 0x20 0x00
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0018 len=0
0x18 0x20 0x00
Device added to RL, Resolving list count = 2
looking up peer sec;
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0009 len=32
0x09 0x20 0x20 0x00 0xa9 0xfb 0x3f 0x02 0x00 0x00 0x00 0x3c 0x1f 0xfc 0x3f 0xc0 0x46 0xfc 0x3f 0x01 0x24 0xf4 0x02 0xfd 0x1f 0x0d 0x80 0xe0 0x64 0xfc 0x3f 0xbc 0xbd 0xfb 0x3f
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0008 len=32
0x08 0x20 0x20 0x0b 0x02 0x01 0x06 0x03 0x03 0x18 0x18 0x03 0x09 0x50 0x4d 0xc0 0x46 0xfc 0x3f 0x01 0x24 0xf4 0x02 0xfd 0x1f 0x0d 0x80 0xe0 0x64 0xfc 0x3f 0xbc 0xbd 0xfb 0x3f
GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0006 len=15
0x06 0x20 0x0f 0x30 0x00 0x60 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x07 0x00
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x000a len=1
0x0a 0x20 0x01 0x01
Server onConnect
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0016 len=2
0x16 0x20 0x02 0x00 0x00
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x01 0x00 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=24
ble_hs_hci_acl_tx(): 0x00 0x00 0x18 0x00 0x14 0x00 0x04 0x00 0x11 0x06 0x01 0x00 0x05 0x00 0x00 0x18 0x06 0x00 0x09 0x00 0x01 0x18 0x0a 0x00 0xff 0xff 0x18 0x18
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x06 0x00 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=18
ble_hs_hci_acl_tx(): 0x00 0x00 0x12 0x00 0x0e 0x00 0x04 0x00 0x11 0x06 0x06 0x00 0x09 0x00 0x01 0x18 0x0a 0x00 0xff 0xff 0x18 0x18
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x0a 0x00 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=12
ble_hs_hci_acl_tx(): 0x00 0x00 0x0c 0x00 0x08 0x00 0x04 0x00 0x11 0x06 0x0a 0x00 0xff 0xff 0x18 0x18
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x00 0x00 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x00 0x00 0x01
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x00 0x00 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x00 0x00 0x01
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x00 0x00 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x00 0x00 0x01
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x00 0x00 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x00 0x00 0x01
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x00 0x00 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x00 0x00 0x01
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
ble_hs_hci_evt_acl_process(): conn_handle=0 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x10 0x42 0x4e 0xff 0xff 0x00 0x28
host tx hci data; handle=0 length=9
ble_hs_hci_acl_tx(): 0x00 0x00 0x09 0x00 0x05 0x00 0x04 0x00 0x01 0x10 0x42 0x4e 0x0a
Server onDisconnect
GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0006 len=15
0x06 0x20 0x0f 0x30 0x00 0x60 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x07 0x00
ble_hs_hci_cmd_send: ogf=0x08 ocf=0x000a len=1
0x0a 0x20 0x01 0x01
start advertising
Update Following Youssif Saeed's insightful suggestions I think I made some progress. Observing the logs from the nRF Connect mobile app while connecting to the ESP32 was not really helpful as there was no error in the pairing or bonding process. However, after cloning the service and setting up the GATT server in nRF Connect I was able to capture the HCI communication. This required using an old rooted Android phone. Now I'm looking at the btsnoop_hci.log file in Wireshark, trying to understand what's going wrong, any pointers are appreciated.
