From d73c52063503e48f503dbee6d31c40236f71c5a7 Mon Sep 17 00:00:00 2001 From: Sylvain Quendez Date: Tue, 15 Oct 2024 16:15:46 +0200 Subject: [PATCH 1/3] 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. --- libraries/BLE/src/BLECharacteristic.cpp | 15 ++++++++++++++- 1 file changed, 14 insertions(+), 1 deletion(-) diff --git a/libraries/BLE/src/BLECharacteristic.cpp b/libraries/BLE/src/BLECharacteristic.cpp index 1d1bafdda1c..90e55d72bab 100644 --- a/libraries/BLE/src/BLECharacteristic.cpp +++ b/libraries/BLE/src/BLECharacteristic.cpp @@ -471,8 +471,21 @@ void BLECharacteristic::notify(bool is_notification) { 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()); - +#endif + if (getService()->getServer()->getConnectedCount() == 0) { log_v("<< notify: No connected clients."); m_pCallbacks->onStatus(this, BLECharacteristicCallbacks::Status::ERROR_NO_CLIENT, 0); From 81b7128553b657e90fd904ad361d3be4e9e9405d Mon Sep 17 00:00:00 2001 From: Sylvain Quendez Date: Fri, 29 Nov 2024 12:28:52 +0100 Subject: [PATCH 2/3] 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. --- libraries/BLE/src/BLECharacteristic.cpp | 30 +++++++++++++++++-------- 1 file changed, 21 insertions(+), 9 deletions(-) diff --git a/libraries/BLE/src/BLECharacteristic.cpp b/libraries/BLE/src/BLECharacteristic.cpp index 90e55d72bab..89a4c60b33f 100644 --- a/libraries/BLE/src/BLECharacteristic.cpp +++ b/libraries/BLE/src/BLECharacteristic.cpp @@ -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()); - char *pHexData = BLEUtils::buildHexData(nullptr, param->write.value, param->write.len); - log_d(" - Data: length: %d, data: %s", param->write.len, pHexData); - free(pHexData); + // 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); + log_d(" - Data: length: %d, data: %s", param->write.len, pHexData); + free(pHexData); + #endif if (param->write.need_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.auth_req = ESP_GATT_AUTH_REQ_NONE; - 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); - free(pHexData); + // 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); + log_d(" - Data: length=%d, data=%s, offset=%d", rsp.attr_value.len, pHexData, rsp.attr_value.offset); + 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); if (errRc != ESP_OK) { @@ -637,9 +645,13 @@ void BLECharacteristic::setReadProperty(bool value) { * @param [in] length The length of the data in bytes. */ void BLECharacteristic::setValue(uint8_t *data, size_t length) { - char *pHex = BLEUtils::buildHexData(nullptr, data, length); - log_v(">> setValue: length=%d, data=%s, characteristic UUID=%s", length, pHex, getUUID().toString().c_str()); - free(pHex); + // 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); + log_v(">> setValue: length=%d, data=%s, characteristic UUID=%s", length, pHex, getUUID().toString().c_str()); + free(pHex); + #endif 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); return; From 8aa3315a1d405563cb0a54d22d00dfc6798f2723 Mon Sep 17 00:00:00 2001 From: "pre-commit-ci-lite[bot]" <117423508+pre-commit-ci-lite[bot]@users.noreply.github.com> Date: Mon, 2 Dec 2024 12:53:45 +0000 Subject: [PATCH 3/3] ci(pre-commit): Apply automatic fixes --- libraries/BLE/src/BLECharacteristic.cpp | 46 ++++++++++++------------- 1 file changed, 23 insertions(+), 23 deletions(-) diff --git a/libraries/BLE/src/BLECharacteristic.cpp b/libraries/BLE/src/BLECharacteristic.cpp index 89a4c60b33f..b03d524a6a5 100644 --- a/libraries/BLE/src/BLECharacteristic.cpp +++ b/libraries/BLE/src/BLECharacteristic.cpp @@ -279,13 +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()); - // 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); - log_d(" - Data: length: %d, data: %s", param->write.len, pHexData); - free(pHexData); - #endif +// 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); + log_d(" - Data: length: %d, data: %s", param->write.len, pHexData); + free(pHexData); +#endif if (param->write.need_rsp) { esp_gatt_rsp_t rsp; @@ -394,13 +394,13 @@ void BLECharacteristic::handleGATTServerEvent(esp_gatts_cb_event_t event, esp_ga rsp.attr_value.handle = param->read.handle; 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); - log_d(" - Data: length=%d, data=%s, offset=%d", rsp.attr_value.len, pHexData, rsp.attr_value.offset); - free(pHexData); - #endif +// 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); + log_d(" - Data: length=%d, data=%s, offset=%d", rsp.attr_value.len, pHexData, rsp.attr_value.offset); + 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); if (errRc != ESP_OK) { @@ -490,10 +490,10 @@ void BLECharacteristic::notify(bool is_notification) { // 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 +#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_VERBOSE GeneralUtils::hexDump((uint8_t *)m_value.getValue().c_str(), m_value.getValue().length()); #endif - + if (getService()->getServer()->getConnectedCount() == 0) { log_v("<< notify: No connected clients."); m_pCallbacks->onStatus(this, BLECharacteristicCallbacks::Status::ERROR_NO_CLIENT, 0); @@ -645,13 +645,13 @@ void BLECharacteristic::setReadProperty(bool value) { * @param [in] length The length of the data in bytes. */ 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); - log_v(">> setValue: length=%d, data=%s, characteristic UUID=%s", length, pHex, getUUID().toString().c_str()); - free(pHex); - #endif +// 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); + log_v(">> setValue: length=%d, data=%s, characteristic UUID=%s", length, pHex, getUUID().toString().c_str()); + free(pHex); +#endif 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); return;