Issues sending characteristic notify - stuck on SEMAPHOR - What am I missing?

[wegunterjr]

D (23428) FreeRTOS: Semaphore taking: name: ConfEvt (0x3ffd4698), owner: <N/A> for notify␛[0m
D (23438) FreeRTOS: Semaphore taken:  name: ConfEvt (0x3ffd4698), owner: notify␛[0m
V (23438) FreeRTOS: >> wait: Semaphore waiting: name: ConfEvt (0x3ffd4698), owner: notify for notify␛[0m

Again, seems that I am having issues with the SEMAPHOR? Am i missing something?

[chegewara]

There is not much info. More logs would be helpful.
Maybe this is your case:
#628 (comment)

[wegunterjr]

Hmmm.. I am setup as a server, a client has connected to me and is sending Write messages over BLE.
I receive the WiFi messages in my BLE callback message, and I am successfully able to connect to WiFi, but it is getting stuck on a semaphor.

D (71908) BLECharacteristic: >> setValue: length=11, data=20574520474f5420495421, characteristic UUID=0d563a58-196a-48ce-ace2-dfec78acc814␛[0m
D (71928) BLECharacteristic: << setValue␛[0m
D (71928) BLECharacteristic: >> notify: length: 11␛[0m
D (71938) GeneralUtils:      00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f  ----------------␛[0m
D (71938) GeneralUtils: 0000 20 57 45 20 47 4f 54 20 49 54 21                  WE GOT IT!␛[0m
D (71948) FreeRTOS: Semaphore taking: name: ConfEvt (0x3ffd4698), owner: <N/A> for notify␛[0m
D (71958) FreeRTOS: Semaphore taken:  name: ConfEvt (0x3ffd4698), owner: notify␛[0m
V (71968) FreeRTOS: >> wait: Semaphore waiting: name: ConfEvt (0x3ffd4698), owner: notify for notify␛[0m

[wegunterjr]

This is how I am setting up my Task:

class bleCharacteristicCallback: public BLECharacteristicCallbacks 
{
	void onWrite(BLECharacteristic* pCharacteristic) 
	{    
		std::string msg = pCharacteristic->getValue();
		ESP_LOGI(LOG_TAG, "BLE received: %s", msg.c_str());
		esp_log_buffer_char(LOG_TAG, msg.c_str(), msg.length());
		esp_log_buffer_hex(LOG_TAG, msg.c_str(), msg.length());
		pCharacteristic->setNotifyProperty(true);
		processMessage(msg, pCharacteristic);
		BLEUUID sentUUID = pCharacteristic->getUUID();
		ESP_LOGI(LOG_TAG, " BLEUUID Sent: %s", sentUUID.toString().c_str());


		pCharacteristic->setValue(" WE GOT IT!");
		pCharacteristic->notify();
		
	}

	void onRead(BLECharacteristic* pCharacteristic) 
	{
		std::string msg = pCharacteristic->getValue();
		ESP_LOGI(LOG_TAG, "BLE received: %s, %i", msg.c_str(), msg.length());
		esp_log_buffer_char(LOG_TAG, msg.c_str(), msg.length());
		esp_log_buffer_hex(LOG_TAG, msg.c_str(), msg.length());
	}
};
 


class MainBLEServer: public Task {
	void run(void *data) {
		ESP_LOGI(LOG_TAG, "Starting BLE work!");

		BLEDevice::init(DEVICE_NAME);
		BLEServer* pServer = BLEDevice::createServer();
        BLEDevice::setEncryptionLevel(ESP_BLE_SEC_ENCRYPT_MITM);

		BLEDevice::setSecurityCallbacks(new MySecurity());
		BLEService* pService = pServer->createService("b08d3132-e7d8-425e-a392-7086b3f56989");
        
		BLECharacteristic* pCharacteristic = pService->createCharacteristic(
			BLEUUID("b08d3132-e7d8-425e-a392-7086b3456789"),
			BLECharacteristic::PROPERTY_BROADCAST |
			BLECharacteristic::PROPERTY_READ  |
			BLECharacteristic::PROPERTY_NOTIFY    | 
			BLECharacteristic::PROPERTY_WRITE //|
			//BLECharacteristic::PROPERTY_INDICATE
		);
	
		pCharacteristic->setValue("Hello World!");

		BLE2902* p2902Descriptor = new BLE2902();
		p2902Descriptor->setNotifications(true);
		pCharacteristic->addDescriptor(p2902Descriptor);
        p2902Descriptor->setAccessPermissions(ESP_GATT_PERM_READ_ENCRYPTED | ESP_GATT_PERM_WRITE_ENCRYPTED);
		pCharacteristic->setCallbacks(new bleCharacteristicCallback());
		pService->start();

		BLEAdvertising* pAdvertising = pServer->getAdvertising();
		pAdvertising->addServiceUUID(BLEUUID(pService->getUUID()));

		BLESecurity* pSecurity = new BLESecurity();

		pSecurity->setAuthenticationMode(ESP_LE_AUTH_REQ_SC_MITM_BOND);
		pSecurity->setCapability(ESP_IO_CAP_OUT);
		pSecurity->setKeySize();
		pSecurity->setInitEncryptionKey(ESP_BLE_ENC_KEY_MASK | ESP_BLE_ID_KEY_MASK);

		pAdvertising->start();
		ESP_LOGI(LOG_TAG, "Advertising started!");
	}
};

In the main, I am starting up the BLE task:

extern "C" 
{
	void app_main();
}

void app_main(void)
{
	ESP_LOGI(LOG_TAG, "Starting!");
	//esp_log_level_set("*", ESP_LOG_DEBUG);
	MainBLEServer* pMainBleServer = new MainBLEServer();
	pMainBleServer->setStackSize(65535);
	pMainBleServer->start();

	ESP_LOGI(LOG_TAG, "After BLE RAM left %d", esp_get_free_heap_size());

} // app_main

[wegunterjr]

Whenever I have the notify set, it gets stuck in the SEMAPHOR like above:

pCharacteristic->setValue(" WE GOT IT!");
pCharacteristic->notify();

[wegunterjr]

@nkolban any suggestions?

[chegewara]

Try to comment semaphores in this part of code:
https://github.com/nkolban/esp32-snippets/blob/master/cpp_utils/BLECharacteristic.cpp#L561-L572

[wegunterjr]

alright. Looking there now.
While I read that, can you consider these questions:
Am I doing something wrong with memory?
I create the BLE Task, and give it a very large stack size, but then I am calling it from a BLE Callback EventHandler - Am i crossing memory somewhere? Should I do another global for access in other parts?

[chegewara]

Before i fix it you can try this code:
#656 (comment)

[wegunterjr]

trying it now....

[wegunterjr]

so far, so good. I can set a value, and notify - doesn't get stuck and disconnect.

[chegewara]

I tested it over 20 hours with 1-3 clients connected, every client sent write request every 50 ms and server on on write sent notification to each client. Ive got no issue, clients could connect and disconnect in mean time.

From my observation i can say its only reliable solution and its not semaphore fault.

[wegunterjr]

oh wait - I was testing with commenting out the wait in the notify function. was that the wrong test?

i was supposed to test the code linked in a different conversation the #656?

[chegewara]

I think it does not matter. I did tests with normal, not commented semaphore.wait. Here is my current repository i am working on with few enhancements. It will be merged here when i decide that passed all my tests.
https://github.com/chegewara/esp32-snippets-enchancements-test

[wegunterjr]

so, it worked without commenting the
// m_semaphoreConfEvt.take("notify");
I am only able to succeed if this is commented out. I am using v3 of the library and not master, so that might make a difference also.

[chegewara]

here you can see latest logs before my esp32 lost power from usb:

I (80333672) SampleClient: 8--> 7392
E (80333710) SampleClient: Notify callback for characteristic beb5483e-36e1-4688-b7f5-ea07361b26a8 of data Time since boot com3: 80333.615981 length 34
I (80333726) SampleClient: 8--> 7392
E (80333770) SampleClient: Notify callback for characteristic beb5483e-36e1-4688-b7f5-ea07361b26a8 of data Time since boot com3: 80333.668192 length 34
I (80333778) SampleClient: 8--> 7392
E (80333800) SampleClient: Notify callback for characteristic beb5483e-36e1-4688-b7f5-ea07361b26a8 of data Time since boot com3: 80333.720985 length 34
I (80333831) SampleClient: 8--> 7392
E (80333860) SampleClient: Notify callback for characteristic beb5483e-36e1-4688-b7f5-ea07361b26a8 of data Time since boot com3: 80333.773192 length 34

over 80000 seconds runtime.