Skip to content

[BLE Client] Deadlock when calling writeValue after registerForNotify #4952

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.

Sign up for GitHub

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

Jump to bottom
Closed
console-netsphere opened this issue Mar 16, 2021 · 5 comments
Closed

[BLE Client] Deadlock when calling writeValue after registerForNotify #4952

console-netsphere opened this issue Mar 16, 2021 · 5 comments

Comments

@console-netsphere
Copy link

console-netsphere commented Mar 16, 2021 •
edited
Loading

Describe your system
Hardware: Custom ESP32 Module
Computer: Windows 10
Core version: 1.0.4
Environment: Arduino IDE

Hardware:

Board: ESP32 Dev Module
Core Installation version: 1.04
IDE name: Arduino IDE
Flash Frequency: 40Mhz
PSRAM enabled: no
Upload Speed: 115200
Computer OS: Windows 10

Description:

My task locks when calling writeValue right after calling registerForNotify.
This is very random and seems to happen most frequently when the client disconnects from the sever and reconnects, and then again tries to register for notifications from server and write a value in the characteristic.
I got from the logs that when calling writeValue it waits forever for a mutex to be released:
m_semaphoreWriteCharEvt.take("writeValue");
It seems that registerForNotify take the writeValue mutex and never releases it, probably waiting for an event release it.
When writeValue is called, it tries to take the mutex and keep waiting forever causing the deadlock.
As a temporary solution I set a task watchdog to panic and reset the device if the situation above happen, but this may be affecting other people projects that a reset is impracticable.
Also, the client is connected and the code is executed right after a scan and successful connection to server.

Sketch:

bool WeAcessBLEClient::elevateConnectionStatus(notify_callback response_callback){

	LOG_MSG("[Info] Informing server that the device is a permanent provider...");

	if(!isClientConnected()){
		LOG_MSG("[Error] We are not connected, or the client is NULL");
		return false;
	}

	/* First we get the tag service */
	BLERemoteService *tag_serv =
			bleClient->getService(TAG_SERVICE);
	if(!tag_serv){
		LOG_MSG("[Error] Could not get service for TAGs");
		return false;
	}


	/* Then we write the permanent provider key in the related characteristic */
	BLERemoteCharacteristic *perm_char =
			tag_serv->getCharacteristic(PERM_TAG_PROVIDER_CHARACT);
	if(!perm_char){
		LOG_MSG("[Error] Could not get characteristic for permanent TAG provider.");
		return false;
	}

	/*Register to grab authentication status from server */
	perm_char->registerForNotify(response_callback);
	delay(100);
	LOG_MSG("Registered to server notifications!");
	/* At last We send the permanent provider key to server */
      *** LOCKS IN THE LINE BELOW ****
	perm_char->writeValue(BLE_PERM_CONN_PWD.c_str());
	LOG_MSG("[Info] Registering in server as a permanent provider...");
	return true;
}

Logs

[Info] Found paired device...
[V][BLEScan.cpp:250] stop(): >> stop()
[V][FreeRTOS.cpp:143] give(): Semaphore giving: name: ScanEnd (0x3ffdf884), owner: start
[V][BLEScan.cpp:262] stop(): << stop()
[V][FreeRTOS.cpp:77] wait(): << wait: Semaphore released: name: ScanEnd (0x3ffdf884), owner: <N/A>
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEClient.cpp:96] connect(): >> connect(a4:cf:12:45:34:2e)
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[I][BLEDevice.cpp:593] addPeerDevice(): add conn_id: 25, GATT role: client
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[D][FreeRTOS.cpp:189] take(): Semaphore taking: name: RegEvt (0x3ffdfbf8), owner: <N/A> for connect
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][FreeRTOS.cpp:198] take(): Semaphore taken:  name: RegEvt (0x3ffdfbf8), owner: connect
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][FreeRTOS.cpp:63] wait(): >> wait: Semaphore waiting: name: RegEvt (0x3ffdfbf8), owner: connect for connect
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 3 0x03
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:1817] gapEventToString(): gapEventToString: Unknown event type 18 0x12
[V][BLEUtils.cpp:1049] dumpGapEvent(): Received a GAP event: Unknown event type
[V][BLEUtils.cpp:1264] dumpGapEvent(): *** dumpGapEvent: Logger not coded ***
[D][BLEClient.cpp:457] handleGAPEvent(): BLEClient ... handling GAP event!
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 0
[D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 0
[V][BLEUtils.cpp:1283] dumpGattClientEvent(): GATT Event: Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 0
[D][BLEClient.cpp:158] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][FreeRTOS.cpp:143] give(): Semaphore giving: name: RegEvt (0x3ffdfbf8), owner: connect
[V][FreeRTOS.cpp:77] wait(): << wait: Semaphore released: name: RegEvt (0x3ffdfbf8), owner: <N/A>
[D][FreeRTOS.cpp:189] take(): Semaphore taking: name: OpenEvt (0x3ffdfc58), owner: <N/A> for connect
[D][FreeRTOS.cpp:198] take(): Semaphore taken:  name: OpenEvt (0x3ffdfc58), owner: connect
[V][FreeRTOS.cpp:63] wait(): >> wait: Semaphore waiting: name: OpenEvt (0x3ffdfc58), owner: connect for connect
2021/03/15 22:37:52: [V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 40
[D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 40
[V][BLEUtils.cpp:1283] dumpGattClientEvent(): GATT Event: Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 40
[D][BLEClient.cpp:158] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[D][BLEDevice.cpp:577] updatePeerDevice(): update conn_id: 4, GATT role: client
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 2
[D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 2
[V][BLEUtils.cpp:1283] dumpGattClientEvent(): GATT Event: Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 2
[D][BLEClient.cpp:158] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][FreeRTOS.cpp:143] give(): Semaphore giving: name: OpenEvt (0x3ffdfc58), owner: connect
[V][FreeRTOS.cpp:77] wait(): << wait: Semaphore released: name: OpenEvt (0x3ffdfc58), owner: <N/A>
[V][BLEClient.cpp:129] connect(): << connect(), rc=1
[Info] Connected to target device at address a4:cf:12:45:34:2e
[DEBUG] Changing task WDT to 10 seconds!
[Info] Informing server that the device is a permanent provider...
[V][BLEClient.cpp:377] getService(): >> getService: uuid: 45b70d8c-19ee-414c-a31f-c4fa3ee3eaa0
[V][BLEClient.cpp:390] getService(): << getService: found the service with uuid: 45b70d8c-19ee-414c-a31f-c4fa3ee3eaa0
[V][BLERemoteCharacteristic.cpp:438] registerForNotify(): >> registerForNotify(): Characteristic: uuid: c3a2dcd7-6ec9-42da-a74f-b7dfb86a74cb, handle: 59 0x003b, props: broadcast: 0, read: 0, write_nr: 0, write: 1, notify: 1, indicate: 0, auth: 0
[D][FreeRTOS.cpp:189] take(): Semaphore taking: name: RegForNotifyEvt (0x3ffe23c0), owner: <N/A> for registerForNotify
[D][FreeRTOS.cpp:198] take(): Semaphore taken:  name: RegForNotifyEvt (0x3ffe23c0), owner: registerForNotify
[V][BLERemoteCharacteristic.cpp:323] getDescriptor(): >> getDescriptor: uuid: 00002902-0000-1000-8000-00805f9b34fb
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 38
[V][BLERemoteCharacteristic.cpp:327] getDescriptor(): << getDescriptor: found
[D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][BLERemoteDescriptor.cpp:132] writeValue(): >> writeValue: handle: 60, uuid: 00002902-0000-1000-8000-00805f9b34fb
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 38
[V][BLERemoteDescriptor.cpp:151] writeValue(): << writeValue
[V][BLEUtils.cpp:1283] dumpGattClientEvent(): GATT Event: Unknown
[V][FreeRTOS.cpp:63] wait(): >> wait: Semaphore waiting: name: RegForNotifyEvt (0x3ffe23c0), owner: registerForNotify for registerForNotify
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 38
[D][BLEClient.cpp:158] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][FreeRTOS.cpp:143] give(): Semaphore giving: name: RegForNotifyEvt (0x3ffe23c0), owner: registerForNotify
[V][FreeRTOS.cpp:77] wait(): << wait: Semaphore released: name: RegForNotifyEvt (0x3ffe23c0), owner: <N/A>
[V][BLERemoteCharacteristic.cpp:478] registerForNotify(): << registerForNotify()
Registered to server notifications!
[V][BLERemoteCharacteristic.cpp:549] writeValue(): >> writeValue(), length: 8
[D][FreeRTOS.cpp:189] take(): Semaphore taking: name: WriteCharEvt (0x3ffe2420), owner: <N/A> for writeValue
[D][FreeRTOS.cpp:198] take(): Semaphore taken:  name: WriteCharEvt (0x3ffe2420), owner: writeValue
[V][FreeRTOS.cpp:63] wait(): >> wait: Semaphore waiting: name: WriteCharEvt (0x3ffe2420), owner: writeValue for writeValue
[Info] HMI Task Received Command Connected!
2021/03/15 22:37:59: [V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 41
[D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 41
[V][BLEUtils.cpp:1283] dumpGattClientEvent(): GATT Event: Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 41
[D][BLEClient.cpp:158] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][FreeRTOS.cpp:143] give(): Semaphore giving: name: OpenEvt (0x3ffdfc58), owner: <N/A>
[V][FreeRTOS.cpp:143] give(): Semaphore giving: name: RssiCmplEvt (0x3ffdfd18), owner: <N/A>
[V][FreeRTOS.cpp:143] give(): Semaphore giving: name: SearchCmplEvt (0x3ffdfcb8), owner: <N/A>
[I][BLEDevice.cpp:604] removePeerDevice(): remove: 25, GATT role client
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 5
[D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 5
[V][BLEUtils.cpp:1283] dumpGattClientEvent(): GATT Event: Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 1
[D][BLEDevice.cpp:148] gattClientEventHandler(): gattClientEventHandler [esp_gatt_if: 4] ... Unknown
[V][BLEUtils.cpp:951] gattClientEventTypeToString(): Unknown GATT Client event type: 1
[V][BLEUtils.cpp:1283] dumpGattClientEvent(): GATT Event: Unknown
@console-netsphere console-netsphere changed the title [BLE Client] Deadlock when calling writeValue after registerForNotify sometimes [BLE Client] Deadlock when calling writeValue after registerForNotify Mar 16, 2021
@h2zero
Copy link
Contributor

h2zero commented Mar 17, 2021 •
edited
Loading

I really need to find my old code fixes for this library and PR them.

The issue here is your device has been disconnected while you were waiting for the write to complete and are now stuck on the semaphore as that event is not handled properly to release it in the BLERemoteChracteristic class.

Here is the fix; Add this code to this line:

case ESP_GATTC_DISCONNECT_EVT: {
        m_semaphoreWriteCharEvt.give(1);
	break;
}

That should resolve this issue.

@console-netsphere
Copy link
Author

Thank you for providing the fix.
It would be nice to have this fix included in the next release.

me-no-dev added a commit that referenced this issue Mar 17, 2021
@me-no-dev
[BLE Client] Fix Deadlock when calling writeValue after registerForNo…
9a0762a 
…tify

Fixes: #4952
@me-no-dev
Copy link
Member

it will :)

@h2zero
Copy link
Contributor

h2zero commented Mar 17, 2021

Nice :)

@ninja-
Copy link

ninja- commented May 17, 2021

nice

@Rotzbua Rotzbua mentioned this issue Oct 1, 2022
Closed
1 task
@uwec uwec mentioned this issue May 1, 2023
Merged
10 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@ninja- @me-no-dev @h2zero @console-netsphere