BLECharacteristic optimization (#10665)

* BLECharacteristic::notify() optimization

GeneralUtils::hexDump() doesn't output anything if the log level is not "VERBOSE". Additionally, it is very CPU intensive, even when it doesn't output anything. So it is much better to *not* call it at all if not needed. 

In a simple program which calls BLECharacteristic::notify() every 50 ms, the performance gain of this little optimization is 37% in release mode (-O3) and 57% in debug mode. 

Of course, the "#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_VERBOSE" guard could also be put inside the GeneralUtils::hexDump() function itself. But it's better to put it here also, as it is clearer (indicating a verbose log thing) and it allows to remove the "m_value.getValue().c_str()" call, which is in itself quite CPU intensive.

* BLECharacteristic optimization

Calls to BLEUtils::buildHexData() don't output anything when the log level is not "VERBOSE" or "DEBUG". As this function is quite CPU intensive, it is better to not call it when not needed.
This commit is contained in:
Sylvain Quendez 2024-12-03 15:10:51 +01:00 committed by GitHub
parent 98da424de6
commit 6ce43695d2
No known key found for this signature in database
GPG key ID: B5690EEEBB952194

View file

@ -279,9 +279,13 @@ void BLECharacteristic::handleGATTServerEvent(esp_gatts_cb_event_t event, esp_ga
log_d(" - Response to write event: New value: handle: %.2x, uuid: %s", getHandle(), getUUID().toString().c_str()); log_d(" - Response to write event: New value: handle: %.2x, uuid: %s", getHandle(), getUUID().toString().c_str());
// The call to BLEUtils::buildHexData() doesn't output anything if the log level is not
// "DEBUG". As it is quite CPU intensive, it is much better to not call it if not needed.
#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_DEBUG
char *pHexData = BLEUtils::buildHexData(nullptr, param->write.value, param->write.len); char *pHexData = BLEUtils::buildHexData(nullptr, param->write.value, param->write.len);
log_d(" - Data: length: %d, data: %s", param->write.len, pHexData); log_d(" - Data: length: %d, data: %s", param->write.len, pHexData);
free(pHexData); free(pHexData);
#endif
if (param->write.need_rsp) { if (param->write.need_rsp) {
esp_gatt_rsp_t rsp; esp_gatt_rsp_t rsp;
@ -390,9 +394,13 @@ void BLECharacteristic::handleGATTServerEvent(esp_gatts_cb_event_t event, esp_ga
rsp.attr_value.handle = param->read.handle; rsp.attr_value.handle = param->read.handle;
rsp.attr_value.auth_req = ESP_GATT_AUTH_REQ_NONE; rsp.attr_value.auth_req = ESP_GATT_AUTH_REQ_NONE;
// The call to BLEUtils::buildHexData() doesn't output anything if the log level is not
// "DEBUG". As it is quite CPU intensive, it is much better to not call it if not needed.
#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_DEBUG
char *pHexData = BLEUtils::buildHexData(nullptr, rsp.attr_value.value, rsp.attr_value.len); char *pHexData = BLEUtils::buildHexData(nullptr, rsp.attr_value.value, rsp.attr_value.len);
log_d(" - Data: length=%d, data=%s, offset=%d", rsp.attr_value.len, pHexData, rsp.attr_value.offset); log_d(" - Data: length=%d, data=%s, offset=%d", rsp.attr_value.len, pHexData, rsp.attr_value.offset);
free(pHexData); free(pHexData);
#endif
esp_err_t errRc = ::esp_ble_gatts_send_response(gatts_if, param->read.conn_id, param->read.trans_id, ESP_GATT_OK, &rsp); esp_err_t errRc = ::esp_ble_gatts_send_response(gatts_if, param->read.conn_id, param->read.trans_id, ESP_GATT_OK, &rsp);
if (errRc != ESP_OK) { if (errRc != ESP_OK) {
@ -471,7 +479,20 @@ void BLECharacteristic::notify(bool is_notification) {
m_pCallbacks->onNotify(this); // Invoke the notify callback. m_pCallbacks->onNotify(this); // Invoke the notify callback.
// GeneralUtils::hexDump() doesn't output anything if the log level is not
// "VERBOSE". Additionally, it is very CPU intensive, even when it doesn't
// output anything! So it is much better to *not* call it at all if not needed.
// In a simple program which calls BLECharacteristic::notify() every 50 ms,
// the performance gain of this little optimization is 37% in release mode
// (-O3) and 57% in debug mode.
// Of course, the "#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_VERBOSE" guard
// could also be put inside the GeneralUtils::hexDump() function itself. But
// it's better to put it here also, as it is clearer (indicating a verbose log
// thing) and it allows to remove the "m_value.getValue().c_str()" call, which
// is, in itself, quite CPU intensive.
#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_VERBOSE
GeneralUtils::hexDump((uint8_t *)m_value.getValue().c_str(), m_value.getValue().length()); GeneralUtils::hexDump((uint8_t *)m_value.getValue().c_str(), m_value.getValue().length());
#endif
if (getService()->getServer()->getConnectedCount() == 0) { if (getService()->getServer()->getConnectedCount() == 0) {
log_v("<< notify: No connected clients."); log_v("<< notify: No connected clients.");
@ -624,9 +645,13 @@ void BLECharacteristic::setReadProperty(bool value) {
* @param [in] length The length of the data in bytes. * @param [in] length The length of the data in bytes.
*/ */
void BLECharacteristic::setValue(uint8_t *data, size_t length) { void BLECharacteristic::setValue(uint8_t *data, size_t length) {
// The call to BLEUtils::buildHexData() doesn't output anything if the log level is not
// "VERBOSE". As it is quite CPU intensive, it is much better to not call it if not needed.
#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_VERBOSE
char *pHex = BLEUtils::buildHexData(nullptr, data, length); char *pHex = BLEUtils::buildHexData(nullptr, data, length);
log_v(">> setValue: length=%d, data=%s, characteristic UUID=%s", length, pHex, getUUID().toString().c_str()); log_v(">> setValue: length=%d, data=%s, characteristic UUID=%s", length, pHex, getUUID().toString().c_str());
free(pHex); free(pHex);
#endif
if (length > ESP_GATT_MAX_ATTR_LEN) { if (length > ESP_GATT_MAX_ATTR_LEN) {
log_e("Size %d too large, must be no bigger than %d", length, ESP_GATT_MAX_ATTR_LEN); log_e("Size %d too large, must be no bigger than %d", length, ESP_GATT_MAX_ATTR_LEN);
return; return;