Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Dual-mode BLEServer misidentifies client connection as server connection, performs unnecessary transmission and warning #10573

Open
1 task done
ArdenKolodner opened this issue Nov 5, 2024 · 3 comments
Labels
Area: BLE Issues related to BLE

Comments

@ArdenKolodner
Copy link

ArdenKolodner commented Nov 5, 2024

Board

ESP32C3

Device Description

Plain module attached by USB-C

Hardware Configuration

The issue occurs when no other hardware is present.

Version

latest master (checkout manually)

IDE Name

VSCode

Operating System

macOS 14.6.1

Flash frequency

80MHz

PSRAM enabled

yes

Upload speed

115200

Description

I have an ESP32-C3 in dual-mode BLE. I'll call it the central device. It has a client connection to another device (also an ESP32-C3), which I'll call the peripheral device. It is also a server (BLEServer via BLEDevice::createServer()) which has a client connected to it. That client is my laptop.

When sending a BLE notification with a characteristic value longer than 20 bytes, I got the following warning:
[W][BLECharacteristic.cpp:527] notify(): - Truncating to 20 bytes (maximum notify size)
However, the server had set its MTU to 500 via BLEDevice::setMTU(500). I tried using multiple BLE client applications (LightBlue, Python via Bleak, and react-native-ble-plx), confirming that the warning occurs with all of them. Additionally, all can support an MTU of 500, so there shouldn't be any truncation. Indeed, all of the data was being transmitted successfully, with no truncation, despite the warning.

During debugging, I found that the warning is not being generated when the server sends the notification to my laptop. It's actually trying to send 2 notifications: one to the peripheral device, and one to my laptop. The laptop one works fine, but the peripheral device's negotiated MTU is 23, which is too short. I didn't bother to have the peripheral select an MTU because it's not supposed to be receiving notifications from the server – it's a server as well, not a client! The server should not be sending notifications to it in the first place.

I think the problem is that the connection to the peripheral device, which is a client connection, is getting misidentified as a server connection. When the central device connects to the peripheral, BLEServer::addPeerDevice gets called with _client set to false, so the central device mistakenly thinks this connection is from an incoming client, instead of what's really going on, which is that the central device is the client. Then the connection gets added to m_connectedServersMap . However, this would happen even if _client were true – the argument is totally ignored. But then later, when BLECharacteristic::notify() calls getService()->getServer()->getPeerDevices(false), the getPeerDevices() method ignores the _client argument again and returns the whole list of peer devices (m_connectedServersMap) which now includes the client connection.

Thus notify() thinks there are two clients to notify instead of just one, and it tries to notify both. The notification to the peripheral device does not throw an error, for some reason - esp_ble_gatts_send_indicate returns ESP_OK for both notifications. But the peripheral device shouldn't be getting it anyway.

The root of the problem seems to be that BLEServer::handleGATTServerEvent() is getting called on an ESP_GATTS_CONNECT_EVT event, when the peripheral device connects. This prompts an addPeerDevice(..., false) call that should not occur. As I don't have a ton of experience with BLE outside of using this library, I don't know why this is happening.

Sketch

Start a BLE server with minimal MTU.

Start a dual-mode BLE device. Have it connect to the server, then start advertising itself. It needs a characteristic that's readable and notifiable.

Connect a BLE client (I recommend LightBlue) to the dual-mode device. Have it subscribe to the characteristic.

Have the server set the characteristic value to something several hundred bytes long, and send a notification.

Debug Message

ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x42096e8c
0x42096e8c: cpu_ll_waiti at ~/esp/esp-idf/components/hal/esp32c3/include/hal/cpu_ll.h:204
 (inlined by) esp_pm_impl_waiti at ~/esp/esp-idf/components/esp_pm/pm_impl.c:837

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd5810,len:0x182c
load:0x403cc710,len:0xc28
load:0x403ce710,len:0x2dfc
entry 0x403cc710
I (24) boot: ESP-IDF v4.4.4-dirty 2nd stage bootloader
I (24) boot: compile time 14:42:32
I (25) boot: chip revision: v0.4
I (27) boot_comm: chip revision: 4, min. bootloader chip revision: 3
I (34) qio_mode: Enabling default flash chip QIO
I (39) boot.esp32c3: SPI Speed      : 80MHz
I (44) boot.esp32c3: SPI Mode       : QIO
I (49) boot.esp32c3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00180000
I (92) boot:  3 storage          Unknown data     01 82 00190000 00180000
I (99) boot: End of partition table
I (104) boot_comm: chip revision: 4, min. application chip revision: 3
I (111) esp_image: segment 0: paddr=00010020 vaddr=3c0e0020 size=398b8h (235704) map
I (153) esp_image: segment 1: paddr=000498e0 vaddr=3fc91800 size=025e0h (  9696) load
I (155) esp_image: segment 2: paddr=0004bec8 vaddr=40380000 size=04150h ( 16720) load
I (162) esp_image: segment 3: paddr=00050020 vaddr=42000020 size=d8180h (885120) map
I (294) esp_image: segment 4: paddr=001281a8 vaddr=40384150 size=0d554h ( 54612) load
I (310) boot: Loaded app from partition at offset 0x10000
I (310) boot: Disabling RNG early entropy source...
Starting...

Connecting to peripheral
[   659][I][BLEDevice.cpp:622] addPeerDevice(): add conn_id: 0, GATT role: client
[   659][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_REG_EVT
[   665][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_REG_EVT
[  6048][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_CONNECT_EVT
[  6048][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_CONNECT_EVT
[  6058][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_OPEN_EVT
[  6069][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_OPEN_EVT
[  7327][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... Unknown
[  7327][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... Unknown
[  7406][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_SEARCH_RES_EVT
[  7407][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_SEARCH_RES_EVT
[  7418][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_SEARCH_RES_EVT
[  7428][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_SEARCH_RES_EVT
[  7440][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_SEARCH_RES_EVT
[  7451][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_SEARCH_RES_EVT
[  7462][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_SEARCH_CMPL_EVT
[  7473][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_SEARCH_CMPL_EVT
[  7484][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_CFG_MTU_EVT
[  7495][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_CFG_MTU_EVT
[  7506][D][BLERemoteService.cpp:193] retrieveCharacteristics(): Found a characteristic: Handle: 42, UUID: beb5483e-36e1-4688-b7f5-ea07361b26a8
[  7518][E][BLERemoteCharacteristic.cpp:289] retrieveDescriptors(): esp_ble_gattc_get_all_descr: ESP_GATT_NOT_FOUND
[  7528][D][BLERemoteService.cpp:193] retrieveCharacteristics(): Found a characteristic: Handle: 44, UUID: beb5483e-36e1-4688-b7f5-ea07361b26a9
[  7541][E][BLERemoteCharacteristic.cpp:289] retrieveDescriptors(): esp_ble_gattc_get_all_descr: ESP_GATT_NOT_FOUND
[  7551][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_REG_FOR_NOTIFY_EVT
[  7562][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_REG_FOR_NOTIFY_EVT
[  7575][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_WRITE_CHAR_EVT
[  7585][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_WRITE_CHAR_EVT
[  7647][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_NOTIFY_EVT
[  7648][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_NOTIFY_EVT
[  7658][D][BLERemoteCharacteristic.cpp:165] gattClientEventHandler(): Invoking callback for notification on characteristic Characteristic: uuid: beb5483e-36e1-4688-b7f5-ea07361b26a9, handle: 44 0x002c, props: broadcast: 0, read: 1, write_nr: 0, write: 0, notify: 1, indicate: 0, auth: 0
[  7683][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_NOTIFY_EVT
[  7694][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_NOTIFY_EVT
[  7704][D][BLERemoteCharacteristic.cpp:165] gattClientEventHandler(): Invoking callback for notification on characteristic Characteristic: uuid: beb5483e-36e1-4688-b7f5-ea07361b26a9, handle: 44 0x002c, props: broadcast: 0, read: 1, write_nr: 0, write: 0, notify: 1, indicate: 0, auth: 0
[  8596][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_WRITE_CHAR_EVT
[  8597][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_WRITE_CHAR_EVT
[  8647][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_NOTIFY_EVT
[  8647][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_NOTIFY_EVT
[  8657][D][BLERemoteCharacteristic.cpp:165] gattClientEventHandler(): Invoking callback for notification on characteristic Characteristic: uuid: beb5483e-36e1-4688-b7f5-ea07361b26a9, handle: 44 0x002c, props: broadcast: 0, read: 1, write_nr: 0, write: 0, notify: 1, indicate: 0, auth: 0
[  8808][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_REG_EVT
[  8808][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CONNECT_EVT
[  8820][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CREATE_EVT
[  8829][D][BLEService.cpp:225] addCharacteristic(): Adding characteristic: uuid=b62c1eb3-3d58-422b-b98b-441e351ff1fe to service: UUID: 94289ed5-65a5-463c-9730-71e4513964ae, handle: 0x0028
[  8845][D][BLEService.cpp:225] addCharacteristic(): Adding characteristic: uuid=ca9e7331-3b32-49fa-8061-46312b73cefb to service: UUID: 94289ed5-65a5-463c-9730-71e4513964ae, handle: 0x0028
[  8862][D][BLECharacteristic.cpp:90] executeCreate(): Registering characteristic (esp_ble_gatts_add_char): uuid: b62c1eb3-3d58-422b-b98b-441e351ff1fe, service: UUID: 94289ed5-65a5-463c-9730-71e4513964ae, handle: 0x0028
[  8881][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_ADD_CHAR_EVT
[  8946][D][BLECharacteristic.cpp:90] executeCreate(): Registering characteristic (esp_ble_gatts_add_char): uuid: ca9e7331-3b32-49fa-8061-46312b73cefb, service: UUID: 94289ed5-65a5-463c-9730-71e4513964ae, handle: 0x0028
[  8960][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_ADD_CHAR_EVT
[  8971][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_ADD_CHAR_DESCR_EVT
[  8983][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_START_EVT
[  8992][I][BLEDevice.cpp:577] getAdvertising(): create advertising
[  8998][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9004][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9010][D][BLEAdvertising.cpp:199] start(): - advertising service: 94289ed5-65a5-463c-9730-71e4513964ae
[  9020][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9026][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9032][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 0]
W (9899) BT_BTM: BTM_BleWriteScanRsp, Partial data write into ADV
[  9107][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9107][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9109][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 1]
[  9118][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9123][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9129][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 6]
[  9137][D][esp32-hal-adc.c:190] __analogReadMilliVolts(): eFuse Two Point: Supported
[  9144][I][esp32-hal-adc.c:232] __analogReadMilliVolts(): ADC1: Characterized using Two Point Value: 0

Server started
W (10106) BT_SMP: FOR LE SC LTK IS USED INSTEAD OF STK
[  9449][D][BLEDevice.cpp:247] gapEventHandler(): ESP_GAP_BLE_KEY_EVT
[  9449][I][BLEDevice.cpp:249] gapEventHandler(): key type = ESP_LE_KEY_PID
[  9451][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9458][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9464][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 9]
[  9471][D][BLEDevice.cpp:247] gapEventHandler(): ESP_GAP_BLE_KEY_EVT
[  9477][I][BLEDevice.cpp:249] gapEventHandler(): key type = ESP_LE_KEY_LENC
[  9484][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9491][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9497][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 9]
[  9504][D][BLEDevice.cpp:247] gapEventHandler(): ESP_GAP_BLE_KEY_EVT
[  9511][I][BLEDevice.cpp:249] gapEventHandler(): key type = ESP_LE_KEY_PENC
[  9517][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9525][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9530][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 9]
[  9538][D][BLEDevice.cpp:247] gapEventHandler(): ESP_GAP_BLE_KEY_EVT
[  9544][I][BLEDevice.cpp:249] gapEventHandler(): key type = ESP_LE_KEY_LID
[  9550][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9558][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9563][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 9]
[  9627][I][BLEDevice.cpp:253] gapEventHandler(): ESP_GAP_BLE_AUTH_CMPL_EVT
SecurityCallback - Authentication Success
[  9627][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9632][D][BLEAdvertising.cpp:199] start(): - advertising service: 94289ed5-65a5-463c-9730-71e4513964ae
[  9641][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9649][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9654][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 8]
W (10522) BT_BTM: BTM_BleWriteScanRsp, Partial data write into ADV
[  9671][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9676][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9682][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 0]
[  9689][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9696][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9702][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 1]
[  9709][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[  9716][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[  9722][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 6]
[ 39333][I][BLEDevice.cpp:253] gapEventHandler(): ESP_GAP_BLE_AUTH_CMPL_EVT
SecurityCallback - Authentication Success
[ 39334][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 39338][D][BLEAdvertising.cpp:199] start(): - advertising service: 94289ed5-65a5-463c-9730-71e4513964ae
[ 39348][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[ 39355][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 39361][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 8]
W (40228) BT_BTM: BTM_BleWriteScanRsp, Partial data write into ADV
[ 39378][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CONNECT_EVT
Central is connected to laptop.
[ 39389][D][BLEServer.cpp:365] onConnect(): BLEServerCallbacks
[ 39394][D][BLEServer.cpp:366] onConnect(): BLEServerCallbacks
[ 39400][D][BLEServer.cpp:367] onConnect(): BLEServerCallbacks
[ 39406][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_CONNECT_EVT
[ 39416][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_CONNECT_EVT
[ 39427][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[ 39434][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 39440][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 0]
[ 39447][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[ 39455][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 39460][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 1]
[ 39467][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[ 39475][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 39481][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 6]
[ 39488][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[ 39495][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 39501][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 55]
[ 39508][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_MTU_EVT
[ 39519][D][BLEServer.cpp:378] onMtuChanged(): BLEServerCallbacks
[ 39524][D][BLEServer.cpp:379] onMtuChanged(): BLEServerCallbacks
[ 39530][D][BLEServer.cpp:380] onMtuChanged(): BLEServerCallbacks
[ 39536][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_READ_EVT
[ 42583][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_WRITE_EVT
[ 42583][D][BLEDescriptor.cpp:240] setValue(): Set the value in the GATTS database using handle 0x2d
[ 42592][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_SET_ATTR_VAL_EVT
[ 48781][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_WRITE_EVT
[ 48782][D][BLECharacteristic.cpp:297] handleGATTServerEvent():  - Response to write event: New value: handle: 2a, uuid: b62c1eb3-3d58-422b-b98b-441e351ff1fe
[ 48794][D][BLECharacteristic.cpp:300] handleGATTServerEvent():  - Data: length: 1, data: 24
Command to start notifications received.
[ 48805][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_RESPONSE_EVT
Sending data to software
[ 48819][D][BLECharacteristic.cpp:790] onNotify(): >> onNotify: default
[ 48824][D][BLECharacteristic.cpp:791] onNotify(): << onNotify
[ 48830][W][BLECharacteristic.cpp:526] notify(): - Truncating to 20 bytes (maximum notify size)
[ 48839][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CONF_EVT
[ 48849][D][BLECharacteristic.cpp:796] onStatus(): >> onStatus: default
[ 48855][D][BLECharacteristic.cpp:797] onStatus(): << onStatus
[ 48861][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CONF_EVT
[ 48871][D][BLECharacteristic.cpp:796] onStatus(): >> onStatus: default
[ 48877][D][BLECharacteristic.cpp:797] onStatus(): << onStatus
Sending data to software
[ 50705][D][BLECharacteristic.cpp:790] onNotify(): >> onNotify: default
[ 50710][D][BLECharacteristic.cpp:791] onNotify(): << onNotify
[ 50716][W][BLECharacteristic.cpp:526] notify(): - Truncating to 20 bytes (maximum notify size)
[ 50725][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CONF_EVT
[ 50735][D][BLECharacteristic.cpp:796] onStatus(): >> onStatus: default
[ 50741][D][BLECharacteristic.cpp:797] onStatus(): << onStatus
[ 50747][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CONF_EVT
[ 50757][D][BLECharacteristic.cpp:796] onStatus(): >> onStatus: default
[ 50763][D][BLECharacteristic.cpp:797] onStatus(): << onStatus
Sending data to software
[ 50772][D][BLECharacteristic.cpp:790] onNotify(): >> onNotify: default
[ 50778][D][BLECharacteristic.cpp:791] onNotify(): << onNo[ 50783][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_WRITE_EVT
[ 50793][D][BLECharacteristic.cpp:297] handleGATTServerEvent():  - Response to write event: New value: handle: 2a, uuid: b62c1eb3-3d58-422b-b98b-441e351ff1fe
[ 50807][D][BLECharacteristic.cpp:300] handleGATTServerEvent():  - Data: length: 1, data: 23
Command to stop notifications received.
[ 50818][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_RESPONSE_EVT
tify
[ 50829][W][BLECharacteristic.cpp:526] notify(): - Truncating to 20 bytes (maximum notify size)
[ 50838][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CONF_EVT
[ 50848][D][BLECharacteristic.cpp:796] onStatus(): >> onStatus: default
[ 50854][D][BLECharacteristic.cpp:797] onStatus(): << onStatus
[ 50860][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_CONF_EVT
[ 50870][D][BLECharacteristic.cpp:796] onStatus(): >> onStatus: default
[ 50876][D][BLECharacteristic.cpp:797] onStatus(): << onStatus
W (53094) BT_HCI: hcif disc complete: hdl 0x2, rsn 0x13
W (53095) BT_APPL: gattc_conn_cb: if=3 st=0 id=259 rsn=0x13
[ 52237][D][BLEDevice.cpp:102] gattServerEventHandler(): gattServerEventHandler [esp_gatt_if: 4] ... ESP_GATTS_DISCONNECT_EVT
Central is disconnected from laptop. Note: the peripheral is still connected at this point.
[ 52251][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 52256][D][BLEAdvertising.cpp:199] start(): - advertising service: 94289ed5-65a5-463c-9730-71e4513964ae
[ 52266][D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_DISCONNECT_EVT
[ 52277][D][BLEClient.cpp:178] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 3] ... ESP_GATTC_DISCONNECT_EVT
W (53148) BT_BTM: BTM_BleWriteScanRsp, Partial data write into ADV
[ 52297][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[ 52302][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 52307][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 0]
[ 52315][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[ 52322][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 52328][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 1]
[ 52335][D][BLEClient.cpp:493] handleGAPEvent(): BLEClient ... handling GAP event!
[ 52342][D][BLEDevice.cpp:579] getAdvertising(): get advertising
[ 52348][D][BLEAdvertising.cpp:506] handleGAPEvent(): handleGAPEvent [event no: 6]

Other Steps to Reproduce

No response

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

  • I confirm I have checked existing issues, online documentation and Troubleshooting guide.
@ArdenKolodner ArdenKolodner added the Status: Awaiting triage Issue is waiting for triage label Nov 5, 2024
@SuGlider SuGlider added Area: BLE Issues related to BLE and removed Status: Awaiting triage Issue is waiting for triage labels Nov 5, 2024
@ArdenKolodner
Copy link
Author

ArdenKolodner commented Nov 6, 2024

Another note on this that I just discovered: the log_w("- Truncating to %d bytes (maximum notify size)", _mtu - 3); line turns out to take a total of 9ms to run(!!), which was single-handedly throttling my device's BLE throughput rates – our goal is 10ms per packet, but we have our own processing to do between packets, of course. This could be solved by having the peripheral device increase its MTU, but then there's more unnecessary data being transmitted, also throttling throughput. So a benefit of fixing this issue will be an immediate and automatic increase in BLE transmission times for packets above 23 bytes!
Update: Lowering the Arduino log level to Error (or no output) fixes this, actually. Should have thought of that earlier lol.

@SuGlider
Copy link
Collaborator

SuGlider commented Nov 9, 2024

@ArdenKolodner -
From the log, it sounds like it is an Arduino as Component project.

In order to verify the issue, we need a minimum Arduino Sketch that can be used to reproduce the issue and latter to verify a potential fix.
Please provide such sketch, but have in mind that we don't fix IDF Code, only the ESP32 Arduino Core or its official libraries.

@ArdenKolodner
Copy link
Author

ArdenKolodner commented Nov 10, 2024

@SuGlider Here is a sketch. I cobbled it together from the Arduino example sketches for BLE client and server, so it should be as close to a textbook example as possible. The steps to use it: set up a BLE server that has a service and characteristic given by clientServiceUUID and clientCharUUID (or change their values), then on another device (I used an ESP32S3 dev board), turn the debug log level to Warning or above and upload this sketch. You should see that the client connection triggers the server connection callback, and when notify() is called, it will cause the truncation warning to occur because the server is trying to incorrectly send notification data to the client. You can also connect a client with high MTU, such as a laptop to see that that will receive the data correctly, without causing another warning. Please let me know if anything is unclear.

(Side note: I've noticed a possibly related bug where disconnecting the peripheral device will also cause the server to forcibly disconnect all clients connected to it, because it thinks the server's connections are actually client connections with 0 servers using them. This may be related, but is definitely a bug in the Bluedroid stack implementation that ESP32 uses, not Arduino. I can provide more info on it if you discover that it's relevant.)

dual_mode_double_notify_bug.ino.zip

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area: BLE Issues related to BLE
Projects
None yet
Development

No branches or pull requests

2 participants