BLE: add traces to gatt client (#14165)

* add traces to gatt client

* add files to cmakelists

Co-Authored-By: Vincent Coubard <vincent.coubard@arm.com>

* fixed tracing variable name

Co-Authored-By: Vincent Coubard <vincent.coubard@arm.com>

* add pal tracing

* add more traces for successfull actions

* put write and read as tr_debug in pal

Co-authored-by: Vincent Coubard <vincent.coubard@arm.com>
pull/14198/head
Paul Szczepanek 2021-01-21 10:12:53 +00:00 committed by Paul Szczepanek
parent 7b08388be6
commit 91d4b48989
5 changed files with 322 additions and 7 deletions

View File

@ -7,6 +7,11 @@ add_subdirectory(gatt)
add_subdirectory(generic)
add_subdirectory(pal)
target_include_directories(mbed-ble
INTERFACE
.
)
target_sources(mbed-ble
INTERFACE
BLE.cpp
@ -14,6 +19,7 @@ target_sources(mbed-ble
GattClient.cpp
GattServer.cpp
SecurityManager.cpp
common/ble_trace_helpers.cpp
)
target_link_libraries(mbed-ble

View File

@ -16,10 +16,192 @@
*/
#include "ble_trace_helpers.h"
#include "pal/AttServerMessage.h"
#include "ble-host/include/att_api.h"
#define TRACE_GROUP "BLE "
namespace ble {
#if MBED_CONF_MBED_TRACE_ENABLE
const char* ble_error_to_string(ble_error_t error_code)
{
#if MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
const char* ret = "INVALID ENUM VALUE";
switch(error_code)
{
case BLE_ERROR_NONE: ret = "BLE_ERROR_NONE"; break;
case BLE_ERROR_BUFFER_OVERFLOW: ret = "BLE_ERROR_BUFFER_OVERFLOW"; break;
case BLE_ERROR_NOT_IMPLEMENTED: ret = "BLE_ERROR_NOT_IMPLEMENTED"; break;
case BLE_ERROR_PARAM_OUT_OF_RANGE: ret = "BLE_ERROR_PARAM_OUT_OF_RANGE"; break;
case BLE_ERROR_INVALID_PARAM: ret = "BLE_ERROR_INVALID_PARAM"; break;
case BLE_STACK_BUSY: ret = "BLE_STACK_BUSY"; break;
case BLE_ERROR_INVALID_STATE: ret = "BLE_ERROR_INVALID_STATE"; break;
case BLE_ERROR_NO_MEM: ret = "BLE_ERROR_NO_MEM"; break;
case BLE_ERROR_OPERATION_NOT_PERMITTED: ret = "BLE_ERROR_OPERATION_NOT_PERMITTED"; break;
case BLE_ERROR_INITIALIZATION_INCOMPLETE: ret = "BLE_ERROR_INITIALIZATION_INCOMPLETE"; break;
case BLE_ERROR_ALREADY_INITIALIZED: ret = "BLE_ERROR_ALREADY_INITIALIZED"; break;
case BLE_ERROR_UNSPECIFIED: ret = "BLE_ERROR_UNSPECIFIED"; break;
case BLE_ERROR_INTERNAL_STACK_FAILURE: ret = "BLE_ERROR_INTERNAL_STACK_FAILURE"; break;
case BLE_ERROR_NOT_FOUND: ret = "BLE_ERROR_NOT_FOUND"; break;
}
#else // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
static char ret[3] = "00";
sprintf(ret, "0x%02x", (int)error_code);
#endif // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
return ret;
}
const char* attribute_error_code_to_string(uint8_t error_code)
{
#if MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
const char* ret = "INVALID ENUM VALUE";
switch(error_code)
{
case AttErrorResponse::INVALID_HANDLE: ret = "INVALID_HANDLE"; break;
case AttErrorResponse::READ_NOT_PERMITTED: ret = "READ_NOT_PERMITTED"; break;
case AttErrorResponse::WRITE_NOT_PERMITTED: ret = "WRITE_NOT_PERMITTED"; break;
case AttErrorResponse::INVALID_PDU: ret = "INVALID_PDU"; break;
case AttErrorResponse::INSUFFICIENT_AUTHENTICATION: ret = "INSUFFICIENT_AUTHENTICATION"; break;
case AttErrorResponse::REQUEST_NOT_SUPPORTED: ret = "REQUEST_NOT_SUPPORTED"; break;
case AttErrorResponse::INVALID_OFFSET: ret = "INVALID_OFFSET"; break;
case AttErrorResponse::INSUFFICIENT_AUTHORIZATION: ret = "INSUFFICIENT_AUTHORIZATION"; break;
case AttErrorResponse::PREPARE_QUEUE_FULL: ret = "PREPARE_QUEUE_FULL"; break;
case AttErrorResponse::ATTRIBUTE_NOT_FOUND: ret = "ATTRIBUTE_NOT_FOUND"; break;
case AttErrorResponse::ATTRIBUTE_NOT_LONG: ret = "ATTRIBUTE_NOT_LONG"; break;
case AttErrorResponse::INSUFFICIENT_ENCRYPTION_KEY_SIZE: ret = "INSUFFICIENT_ENCRYPTION_KEY_SIZE"; break;
case AttErrorResponse::INVALID_ATTRIBUTE_VALUE_LENGTH: ret = "INVALID_ATTRIBUTE_VALUE_LENGTH"; break;
case AttErrorResponse::UNLIKELY_ERROR: ret = "UNLIKELY_ERROR"; break;
case AttErrorResponse::INSUFFICIENT_ENCRYPTION: ret = "INSUFFICIENT_ENCRYPTION"; break;
case AttErrorResponse::UNSUPPORTED_GROUP_TYPE: ret = "UNSUPPORTED_GROUP_TYPE"; break;
case AttErrorResponse::INSUFFICIENT_RESOURCES: ret = "INSUFFICIENT_RESOURCES"; break;
case AttErrorResponse::WRITE_REQUEST_REJECTED: ret = "WRITE_REQUEST_REJECTED"; break;
case AttErrorResponse::CLIENT_CHARACTERISTIC_CONFIGURATION_DESCRIPTOR_IMPROPERLY_CONFIGURED:
ret = "CLIENT_CHARACTERISTIC_CONFIGURATION_DESCRIPTOR_IMPROPERLY_CONFIGURED"; break;
case AttErrorResponse::PROCEDURE_ALREADY_IN_PROGRESS: ret = "PROCEDURE_ALREADY_IN_PROGRESS"; break;
case AttErrorResponse::OUT_OF_RANGE: ret = "OUT_OF_RANGE"; break;
}
#else // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
static char ret[3] = "00";
sprintf(ret, "0x%02x", (int)error_code);
#endif // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
return ret;
}
const char* att_client_callback_event_to_string(uint8_t code)
{
#if MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
const char* ret = "INVALID EVENT";
switch(code)
{
case ATTC_FIND_INFO_RSP: ret = "ATTC_FIND_INFO_RSP"; break;
case ATTC_FIND_BY_TYPE_VALUE_RSP: ret = "ATTC_FIND_BY_TYPE_VALUE_RSP"; break;
case ATTC_READ_BY_TYPE_RSP: ret = "ATTC_READ_BY_TYPE_RSP"; break;
case ATTC_READ_RSP: ret = "ATTC_READ_RSP"; break;
case ATTC_READ_LONG_RSP: ret = "ATTC_READ_LONG_RSP"; break;
case ATTC_READ_MULTIPLE_RSP: ret = "ATTC_READ_MULTIPLE_RSP"; break;
case ATTC_READ_BY_GROUP_TYPE_RSP: ret = "ATTC_READ_BY_GROUP_TYPE_RSP"; break;
case ATTC_WRITE_RSP: ret = "ATTC_WRITE_RSP"; break;
case ATTC_WRITE_CMD_RSP: ret = "ATTC_WRITE_CMD_RSP"; break;
case ATTC_PREPARE_WRITE_RSP: ret = "ATTC_PREPARE_WRITE_RSP"; break;
case ATTC_EXECUTE_WRITE_RSP: ret = "ATTC_EXECUTE_WRITE_RSP"; break;
case ATTC_HANDLE_VALUE_NTF: ret = "ATTC_HANDLE_VALUE_NTF"; break;
case ATTC_HANDLE_VALUE_IND: ret = "ATTC_HANDLE_VALUE_IND"; break;
case ATTC_READ_MULT_VAR_RSP: ret = "ATTC_READ_MULT_VAR_RSP"; break;
case ATTC_MULT_VALUE_NTF: ret = "ATTC_MULT_VALUE_NTF"; break;
case ATTS_HANDLE_VALUE_CNF: ret = "ATTS_HANDLE_VALUE_CNF"; break;
case ATTS_MULT_VALUE_CNF: ret = "ATTS_MULT_VALUE_CNF"; break;
case ATTS_CCC_STATE_IND: ret = "ATTS_CCC_STATE_IND"; break;
case ATTS_DB_HASH_CALC_CMPL_IND: ret = "ATTS_DB_HASH_CALC_CMPL_IND"; break;
case ATT_MTU_UPDATE_IND: ret = "ATT_MTU_UPDATE_IND"; break;
case ATT_EATT_CONN_CMPL_IND: ret = "ATT_EATT_CONN_CMPL_IND"; break;
case ATT_EATT_RECONFIG_CMPL_IND: ret = "ATT_EATT_RECONFIG_CMPL_IND"; break;
}
#else // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
static char ret[3] = "00";
sprintf(ret, "0x%02x", (int)code);
#endif // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
return ret;
}
const char* att_error_code_to_string(uint8_t error_code)
{
#if MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
const char* ret = "INVALID EVENT";
switch(error_code)
{
case ATT_SUCCESS: ret = "ATT_SUCCESS"; break;
case ATT_ERR_HANDLE: ret = "ATT_ERR_HANDLE"; break;
case ATT_ERR_READ: ret = "ATT_ERR_READ"; break;
case ATT_ERR_WRITE: ret = "ATT_ERR_WRITE"; break;
case ATT_ERR_INVALID_PDU: ret = "ATT_ERR_INVALID_PDU"; break;
case ATT_ERR_AUTH: ret = "ATT_ERR_AUTH"; break;
case ATT_ERR_NOT_SUP: ret = "ATT_ERR_NOT_SUP"; break;
case ATT_ERR_OFFSET: ret = "ATT_ERR_OFFSET"; break;
case ATT_ERR_AUTHOR: ret = "ATT_ERR_AUTHOR"; break;
case ATT_ERR_QUEUE_FULL: ret = "ATT_ERR_QUEUE_FULL"; break;
case ATT_ERR_NOT_FOUND: ret = "ATT_ERR_NOT_FOUND"; break;
case ATT_ERR_NOT_LONG: ret = "ATT_ERR_NOT_LONG"; break;
case ATT_ERR_KEY_SIZE: ret = "ATT_ERR_KEY_SIZE"; break;
case ATT_ERR_LENGTH: ret = "ATT_ERR_LENGTH"; break;
case ATT_ERR_UNLIKELY: ret = "ATT_ERR_UNLIKELY"; break;
case ATT_ERR_ENC: ret = "ATT_ERR_ENC"; break;
case ATT_ERR_GROUP_TYPE: ret = "ATT_ERR_GROUP_TYPE"; break;
case ATT_ERR_RESOURCES: ret = "ATT_ERR_RESOURCES"; break;
case ATT_ERR_DATABASE_OUT_OF_SYNC: ret = "ATT_ERR_DATABASE_OUT_OF_SYNC"; break;
case ATT_ERR_VALUE_NOT_ALLOWED: ret = "ATT_ERR_VALUE_NOT_ALLOWED"; break;
case ATT_ERR_WRITE_REJ: ret = "ATT_ERR_WRITE_REJ"; break;
case ATT_ERR_CCCD: ret = "ATT_ERR_CCCD"; break;
case ATT_ERR_IN_PROGRESS: ret = "ATT_ERR_IN_PROGRESS"; break;
case ATT_ERR_RANGE: ret = "ATT_ERR_RANGE"; break;
}
#else // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
static char ret[3] = "00";
sprintf(ret, "0x%02x", (int)error_code);
#endif // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
return ret;
}
const char* attribute_opcode_to_string(uint8_t error_code)
{
#if MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
const char* ret = "INVALID OPCODE";
switch(error_code)
{
case AttributeOpcode::ERROR_RESPONSE: ret = "ERROR_RESPONSE"; break;
case AttributeOpcode::EXCHANGE_MTU_REQUEST: ret = "EXCHANGE_MTU_REQUEST"; break;
case AttributeOpcode::EXCHANGE_MTU_RESPONSE: ret = "EXCHANGE_MTU_RESPONSE"; break;
case AttributeOpcode::FIND_INFORMATION_REQUEST: ret = "FIND_INFORMATION_REQUEST"; break;
case AttributeOpcode::FIND_INFORMATION_RESPONSE: ret = "FIND_INFORMATION_RESPONSE"; break;
case AttributeOpcode::FIND_BY_TYPE_VALUE_REQUEST: ret = "FIND_BY_TYPE_VALUE_REQUEST"; break;
case AttributeOpcode::FIND_BY_VALUE_TYPE_RESPONSE: ret = "FIND_BY_VALUE_TYPE_RESPONSE"; break;
case AttributeOpcode::READ_BY_TYPE_REQUEST: ret = "READ_BY_TYPE_REQUEST"; break;
case AttributeOpcode::READ_BY_TYPE_RESPONSE: ret = "READ_BY_TYPE_RESPONSE"; break;
case AttributeOpcode::READ_REQUEST: ret = "READ_REQUEST"; break;
case AttributeOpcode::READ_RESPONSE: ret = "READ_RESPONSE"; break;
case AttributeOpcode::READ_BLOB_REQUEST: ret = "READ_BLOB_REQUEST"; break;
case AttributeOpcode::READ_BLOB_RESPONSE: ret = "READ_BLOB_RESPONSE"; break;
case AttributeOpcode::READ_MULTIPLE_REQUEST: ret = "READ_MULTIPLE_REQUEST"; break;
case AttributeOpcode::READ_MULTIPLE_RESPONSE: ret = "READ_MULTIPLE_RESPONSE"; break;
case AttributeOpcode::READ_BY_GROUP_TYPE_REQUEST: ret = "READ_BY_GROUP_TYPE_REQUEST"; break;
case AttributeOpcode::READ_BY_GROUP_TYPE_RESPONSE: ret = "READ_BY_GROUP_TYPE_RESPONSE"; break;
case AttributeOpcode::WRITE_REQUEST: ret = "WRITE_REQUEST"; break;
case AttributeOpcode::WRITE_RESPONSE: ret = "WRITE_RESPONSE"; break;
case AttributeOpcode::WRITE_COMMAND: ret = "WRITE_COMMAND"; break;
case AttributeOpcode::SIGNED_WRITE_COMMAND: ret = "SIGNED_WRITE_COMMAND"; break;
case AttributeOpcode::PREPARE_WRITE_REQUEST: ret = "PREPARE_WRITE_REQUEST"; break;
case AttributeOpcode::PREPARE_WRITE_RESPONSE: ret = "PREPARE_WRITE_RESPONSE"; break;
case AttributeOpcode::EXECUTE_WRITE_REQUEST: ret = "EXECUTE_WRITE_REQUEST"; break;
case AttributeOpcode::EXECUTE_WRITE_RESPONSE: ret = "EXECUTE_WRITE_RESPONSE"; break;
case AttributeOpcode::HANDLE_VALUE_NOTIFICATION: ret = "HANDLE_VALUE_NOTIFICATION"; break;
case AttributeOpcode::HANDLE_VALUE_INDICATION: ret = "HANDLE_VALUE_INDICATION"; break;
}
#else // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
static char ret[3] = "00";
sprintf(ret, "0x%02x", (int)error_code);
#endif // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
return ret;
}
const char* dm_callback_event_to_string(uint8_t event) {
#if MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
const char* ret = "INVALID";
@ -121,7 +303,7 @@ const char* dm_callback_event_to_string(uint8_t event) {
}
#else // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
static char ret[3] = "00";
sprintf(ret, "%02x", (int)event);
sprintf(ret, "0x%02x", (int)event);
#endif // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
return ret;
}
@ -328,7 +510,7 @@ const char* hci_opcode_to_string(uint16_t opcode)
}
#else // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
static char ret[3] = "00";
sprintf(ret, "%02x", (int)opcode);
sprintf(ret, "0x%02x", (int)opcode);
#endif // MBED_CONF_BLE_TRACE_HUMAN_READABLE_ENUMS
return ret;
}

View File

@ -22,13 +22,20 @@
#include "mbed-trace/mbed_trace.h"
#include "pal/GapTypes.h"
#include "ble-host/include/dm_api.h"
#include "common/UUID.h"
namespace ble {
#if MBED_CONF_MBED_TRACE_ENABLE
const char* dm_callback_event_to_string(uint8_t event);
void trace_le_supported_features(uint64_t feat);
const char* dm_callback_event_to_string(uint8_t event);
const char* hci_opcode_to_string(uint16_t opcode);
const char* attribute_error_code_to_string(uint8_t error);
const char* attribute_opcode_to_string(uint8_t error);
const char* ble_error_to_string(ble_error_t error);
const char* att_client_callback_event_to_string(uint8_t code);
const char* att_error_code_to_string(uint8_t code);
#endif //MBED_CONF_MBED_TRACE_ENABLE
template<typename T>
@ -37,6 +44,11 @@ static inline const char* tr_as_array(T item)
return (mbed_trace_array)((const uint8_t*)&item, sizeof(item));
}
static inline const char* to_string(UUID uuid)
{
return (mbed_trace_array)(uuid.getBaseUUID(), uuid.getLen());
}
static inline constexpr const char* to_string(bool v)
{
if (v) {

View File

@ -27,6 +27,8 @@
#include "att_api.h"
#include "att_defs.h"
#define TRACE_GROUP "BLAT"
namespace ble {
namespace impl {
@ -41,6 +43,7 @@ PalAttClient::~PalAttClient() = default;
*/
ble_error_t PalAttClient::exchange_mtu_request(connection_handle_t connection)
{
tr_info("Connection %d - AttcMtuReq mtu=%d", connection, pAttCfg->mtu);
AttcMtuReq(connection, pAttCfg->mtu);
return BLE_ERROR_NONE;
}
@ -65,6 +68,7 @@ ble_error_t PalAttClient::find_information_request(
attribute_handle_range_t discovery_range
)
{
tr_info("Connection %d - AttcFindInfoReq handles=[%d:%d]", connection_handle, discovery_range.begin, discovery_range.end);
AttcFindInfoReq(
connection_handle,
discovery_range.begin,
@ -84,6 +88,8 @@ ble_error_t PalAttClient::find_by_type_value_request(
const Span<const uint8_t> &value
)
{
tr_debug("Connection %d - AttcFindByTypeValueReq handles=[%d:%d] type=%d value=%s",
connection_handle, discovery_range.begin, discovery_range.end, type, tr_array(value.data(), value.size()));
AttcFindByTypeValueReq(
connection_handle,
discovery_range.begin,
@ -105,6 +111,8 @@ ble_error_t PalAttClient::read_by_type_request(
const UUID &type
)
{
tr_debug("Connection %d - AttcReadByTypeReq handles=[%d:%d] uuid=%s",
connection_handle, read_range.begin, read_range.end, to_string(type));
AttcReadByTypeReq(
connection_handle,
read_range.begin,
@ -124,6 +132,7 @@ ble_error_t PalAttClient::read_request(
attribute_handle_t attribute_handle
)
{
tr_debug("Connection %d - AttcReadReq handle=%d", connection_handle, attribute_handle);
AttcReadReq(connection_handle, attribute_handle);
return BLE_ERROR_NONE;
}
@ -137,6 +146,7 @@ ble_error_t PalAttClient::read_blob_request(
uint16_t offset
)
{
tr_debug("Connection %d - AttcReadLongReq handle=%d offset=%d", connection_handle, attribute_handle, offset);
AttcReadLongReq(
connection_handle,
attribute_handle,
@ -154,6 +164,8 @@ ble_error_t PalAttClient::read_multiple_request(
const Span<const attribute_handle_t> &attribute_handles
)
{
tr_debug("Connection %d - AttcReadMultipleReq handles=%s",
connection_handle, tr_array((uint8_t*)attribute_handles.data(), attribute_handles.size()));
AttcReadMultipleReq(
connection_handle,
attribute_handles.size(),
@ -171,6 +183,8 @@ ble_error_t PalAttClient::read_by_group_type_request(
const UUID &group_type
)
{
tr_debug("Connection %d - AttcReadByGroupTypeReq handles=[%d:%d] uuid=%s",
connection_handle, read_range.begin, read_range.end, to_string(group_type));
AttcReadByGroupTypeReq(
connection_handle,
read_range.begin,
@ -191,6 +205,8 @@ ble_error_t PalAttClient::write_request(
const Span<const uint8_t> &value
)
{
tr_debug("Connection %d - AttcWriteReq handle=%d value=%s",
connection_handle, attribute_handle, tr_array(value.data(), value.size()));
AttcWriteReq(
connection_handle,
attribute_handle,
@ -209,6 +225,8 @@ ble_error_t PalAttClient::write_command(
const Span<const uint8_t> &value
)
{
tr_debug("Connection %d - AttcWriteCmd handle=%d value=%s",
connection_handle, attribute_handle, tr_array(value.data(), value.size()));
AttcWriteCmd(
connection_handle,
attribute_handle,
@ -227,6 +245,8 @@ ble_error_t PalAttClient::signed_write_command(
const Span<const uint8_t> &value
)
{
tr_debug("Connection %d - AttcSignedWriteCmd handle=%d sign_counter=&d value=%s",
connection_handle, attribute_handle, _local_sign_counter, tr_array(value.data(), value.size()));
AttcSignedWriteCmd(
connection_handle,
attribute_handle,
@ -261,6 +281,8 @@ ble_error_t PalAttClient::prepare_write_request(
const Span<const uint8_t> &value
)
{
tr_debug("Connection %d - AttcPrepareWriteReq handle=%d offset=%d value=%s",
connection_handle, attribute_handle, offset, tr_array(value.data(), value.size()));
AttcPrepareWriteReq(
connection_handle,
attribute_handle,
@ -281,6 +303,8 @@ ble_error_t PalAttClient::execute_write_request(
bool execute
)
{
tr_debug("AttcExecuteWriteReq %d - execute=%s",
connection_handle, to_string(execute));
AttcExecuteWriteReq(
connection_handle,
execute
@ -396,6 +420,7 @@ void PalAttClient::on_transaction_timeout(
connection_handle_t connection_handle
)
{
tr_info("Connection %d - transaction timed out", connection_handle);
if (_transaction_timeout_cb) {
_transaction_timeout_cb(connection_handle);
}
@ -404,6 +429,7 @@ void PalAttClient::on_transaction_timeout(
#if BLE_FEATURE_GATT_CLIENT
void PalAttClient::att_client_handler(const attEvt_t *event)
{
tr_debug("ATT event: %s status: %s", att_client_callback_event_to_string(event->hdr.event), att_error_code_to_string(event->hdr.status));
if (event->hdr.status == ATT_SUCCESS && event->hdr.event == ATT_MTU_UPDATE_IND) {
ble::impl::BLEInstanceBase &ble = BLEInstanceBase::deviceInstance();
PalGattClientEventHandler *handler = ble.getPalGattClient().get_event_handler();

View File

@ -33,6 +33,10 @@
#include "source/pal/AttServerMessage.h"
#include "source/BLEInstanceBase.h"
#include "common/ble_trace_helpers.h"
#define TRACE_GROUP "BLGC"
using ble::AttServerMessage;
using ble::AttReadResponse;
using ble::AttReadBlobResponse;
@ -113,7 +117,7 @@ struct GattClient::ProcedureControlBlock {
/*
* Procedure control block for the discovery process.
*/
#define TRACE_CLASS "DiscoveryControlBlock"
struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
using ProcedureControlBlock::connection_handle;
@ -144,11 +148,13 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
void handle_timeout_error(GattClient *client) final
{
tr_warning("%s timed out", TRACE_CLASS);
terminate(client);
}
void abort(GattClient *client) final
{
tr_warning("%s aborted", TRACE_CLASS);
terminate(client);
}
@ -179,6 +185,7 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
case AttributeOpcode::ERROR_RESPONSE: {
const auto &error = static_cast<const AttErrorResponse &>(message);
if (error.error_code != AttErrorResponse::ATTRIBUTE_NOT_FOUND) {
tr_warning("%s terminating early due to %s", TRACE_CLASS, attribute_error_code_to_string(error.error_code));
terminate(client);
return;
}
@ -206,6 +213,7 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
void handle_service_discovered(GattClient *client, const Response &response)
{
if (!response.size()) {
tr_error("%s terminating due to malformed message", TRACE_CLASS);
terminate(client);
return;
}
@ -216,6 +224,8 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
end_handle = get_end_handle(response[i]);
UUID uuid = get_uuid(response[i]);
tr_debug("Discovered service UUID: %s [0x%x:0x%x])", to_string(uuid), start_handle, end_handle);
if (!characteristic_callback) {
DiscoveredService discovered_service;
discovered_service.setup(uuid, start_handle, end_handle);
@ -250,11 +260,13 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
void start_characteristic_discovery(GattClient *client)
{
if (!services_discovered) {
tr_error("%s terminating due to services list structure null", TRACE_CLASS);
terminate(client);
return;
}
if (!characteristic_callback) {
tr_error("%s terminating due missing characteristic callback", TRACE_CLASS);
terminate(client);
return;
}
@ -293,6 +305,7 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
last_characteristic = characteristic_t(
client, connection_handle, response[i].handle, response[i].value
);
tr_debug("Discovered char handle: 0x%x value: %s", response[i].handle, tr_array(response[i].value.data(), response[i].value.size()));
}
// check if all the characteristics of the service has been discovered
@ -308,6 +321,7 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
);
if (err) {
tr_error("%s terminating early due to %s", TRACE_CLASS, ble_error_to_string(err));
terminate(client);
}
}
@ -328,6 +342,7 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
delete old;
if (!services_discovered) {
tr_debug("Service discovery complete");
terminate(client);
} else {
start_characteristic_discovery(client);
@ -473,7 +488,7 @@ struct GattClient::DiscoveryControlBlock final : public ProcedureControlBlock {
bool done;
};
#define TRACE_CLASS "ReadControlBlock"
struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
using ProcedureControlBlock::connection_handle;
@ -494,6 +509,7 @@ struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
void handle_timeout_error(GattClient *client) final
{
tr_warning("%s timed out", TRACE_CLASS);
GattReadCallbackParams response = {
connection_handle,
attribute_handle,
@ -507,6 +523,7 @@ struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
void abort(GattClient *client) final
{
tr_warning("%s aborted", TRACE_CLASS);
GattReadCallbackParams response = {
connection_handle,
attribute_handle,
@ -543,6 +560,7 @@ struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
default: {
// should not happen, terminate the procedure and notify client with an error
// in such case
tr_error("%s terminated unexpectedly due to unhandled opcode 0x%x", TRACE_CLASS, (int)message.opcode);
GattReadCallbackParams response = {
connection_handle,
attribute_handle,
@ -583,11 +601,13 @@ struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
response.len = (current_offset + read_response.size()) - offset;
response.data = data;
}
tr_info("Read response complete - received %d bytes", read_response.size());
terminate(client, response);
} else {
// allocation which will contain the response data plus the next one.
data = (uint8_t *) realloc(data, (current_offset - offset) + ((mtu_size - 1) * 2));
if (data == nullptr) {
tr_error("%s terminated due to OoM error", TRACE_CLASS);
GattReadCallbackParams response = {
connection_handle,
attribute_handle,
@ -601,6 +621,7 @@ struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
}
memcpy(data + (current_offset - offset), read_response.data(), read_response.size());
tr_info("Read response partial - received %d bytes", read_response.size());
current_offset = current_offset + read_response.size();
ble_error_t err = client->_pal_client.read_attribute_blob(
connection_handle,
@ -609,6 +630,7 @@ struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
);
if (err) {
tr_error("%s terminated because reading attribute failed", TRACE_CLASS);
GattReadCallbackParams response = {
connection_handle,
attribute_handle,
@ -656,6 +678,8 @@ struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
break;
}
tr_error("%s error: %s", TRACE_CLASS, attribute_error_code_to_string(error.error_code));
GattReadCallbackParams response = {
connection_handle,
attribute_handle,
@ -677,7 +701,7 @@ struct GattClient::ReadControlBlock final : public ProcedureControlBlock {
/*
* Control block for the write process
*/
#define TRACE_CLASS "WriteControlBlock"
struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
using ProcedureControlBlock::connection_handle;
@ -699,6 +723,7 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
void handle_timeout_error(GattClient *client) final
{
tr_warning("%s timed out", TRACE_CLASS);
GattWriteCallbackParams response = {
connection_handle,
attribute_handle,
@ -711,6 +736,7 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
void abort(GattClient *client) final
{
tr_warning("%s aborted", TRACE_CLASS);
GattWriteCallbackParams response = {
connection_handle,
attribute_handle,
@ -748,6 +774,8 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
break;
default: {
tr_error("%s terminated due unhandled opcode 0x%x", TRACE_CLASS, (int)message.opcode);
GattWriteCallbackParams response = {
connection_handle,
attribute_handle,
@ -763,6 +791,7 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
void handle_write_response(GattClient* client, const AttWriteResponse& write_response)
{
tr_debug("write executed successfully");
GattWriteCallbackParams response = {
connection_handle,
attribute_handle,
@ -778,6 +807,7 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
{
ble_error_t err = BLE_ERROR_UNSPECIFIED;
offset += write_response.partial_value.size();
tr_info("Prepared write partially complete offset=%d", offset);
uint16_t data_left = write_length - offset; /* offset is guaranteed to be less of equal to write_length */
if (data_left) {
uint16_t chunk_size = client->get_mtu(connection_handle) - PREPARE_WRITE_HEADER_LENGTH;
@ -798,6 +828,7 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
}
if (err) {
tr_error("%s failed due to %s - clearing the queue", TRACE_CLASS, ble_error_to_string(err));
clear_prepare_queue(client, err, AttErrorResponse::UNLIKELY_ERROR);
}
}
@ -805,6 +836,7 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
void handle_execute_write_response(GattClient* client, const AttExecuteWriteResponse& execute_response)
{
if (prepare_success) {
tr_debug("Prepared write executed successfully");
status = BLE_ERROR_NONE;
error_code = 0x00;
}
@ -865,6 +897,8 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
break;
}
tr_error("%s error: %s", TRACE_CLASS, attribute_error_code_to_string(error.error_code));
if (error.request_opcode == AttributeOpcode(AttributeOpcode::PREPARE_WRITE_REQUEST)) {
clear_prepare_queue(client, status, error.error_code);
} else {
@ -892,7 +926,7 @@ struct GattClient::WriteControlBlock final : public ProcedureControlBlock {
/*
* Control block for the descriptor discovery process
*/
#define TRACE_CLASS "DescriptorDiscoveryControlBlock"
struct GattClient::DescriptorDiscoveryControlBlock final : public ProcedureControlBlock {
using ProcedureControlBlock::connection_handle;
@ -913,6 +947,8 @@ struct GattClient::DescriptorDiscoveryControlBlock final : public ProcedureContr
ble_error_t start(GattClient *client)
{
tr_info("Discover descriptor for char handle=%d",
characteristic.getDeclHandle());
return client->_pal_client.discover_characteristics_descriptors(
connection_handle,
attribute_handle_range(
@ -924,11 +960,13 @@ struct GattClient::DescriptorDiscoveryControlBlock final : public ProcedureContr
void handle_timeout_error(GattClient *client) final
{
tr_warning("%s timed out", TRACE_CLASS);
terminate(client, BLE_ERROR_UNSPECIFIED);
}
void abort(GattClient *client) final
{
tr_warning("%s aborted", TRACE_CLASS);
terminate(client, BLE_ERROR_INVALID_STATE);
}
@ -955,6 +993,7 @@ struct GattClient::DescriptorDiscoveryControlBlock final : public ProcedureContr
void handle_error(GattClient *client, const AttErrorResponse &error)
{
tr_error("%s error: %s", TRACE_CLASS, attribute_error_code_to_string(error.error_code));
if (error.error_code == AttErrorResponse::ATTRIBUTE_NOT_FOUND) {
terminate(client, BLE_ERROR_NONE);
} else {
@ -965,6 +1004,8 @@ struct GattClient::DescriptorDiscoveryControlBlock final : public ProcedureContr
void handle_response(GattClient *client, const AttFindInformationResponse &response)
{
for (size_t i = 0; i < response.size(); ++i) {
tr_info("Discovered descriptor handle=%d uuid=%s for char handle=%d",
response[i].handle, to_string(response[i].uuid), characteristic.getDeclHandle());
DiscoveredCharacteristicDescriptor descriptor(
&ble::BLE::Instance().gattClient(), connection_handle, response[i].handle, response[i].uuid
);
@ -993,6 +1034,10 @@ struct GattClient::DescriptorDiscoveryControlBlock final : public ProcedureContr
void terminate(GattClient *client, ble_error_t status, uint8_t error_code = 0x00)
{
if (status != BLE_ERROR_NONE) {
tr_warning("%s terminated due to %s %s", TRACE_CLASS, ble_error_to_string(status), attribute_error_code_to_string(error_code));
}
client->remove_control_block(this);
CharacteristicDescriptorDiscovery::TerminationCallbackParams_t params = {
characteristic,
@ -1039,8 +1084,10 @@ ble_error_t GattClient::launchServiceDiscovery(
const UUID &matching_characteristic_uuid
)
{
tr_info("Launching service discovery (service: %s char: %s)", to_string(matching_service_uuid), to_string(matching_characteristic_uuid));
// verify that there is no other procedures going on this connection
if (_is_reseting || get_control_block(connection_handle)) {
tr_error("cannot launch service discovery");
return BLE_ERROR_INVALID_STATE;
}
@ -1059,6 +1106,7 @@ ble_error_t GattClient::launchServiceDiscovery(
);
if (discovery_pcb == nullptr) {
tr_error("Failed to allocate DiscoveryControlBlock");
return BLE_ERROR_NO_MEM;
}
@ -1082,6 +1130,7 @@ ble_error_t GattClient::launchServiceDiscovery(
}
if (err) {
tr_error("Discovery failed due to %s", ble_error_to_string(err));
remove_control_block(discovery_pcb);
delete discovery_pcb;
}
@ -1095,6 +1144,7 @@ ble_error_t GattClient::discoverServices(
const UUID &matchingServiceUUID
)
{
tr_info("Discover services with uuid=%s", to_string(matchingServiceUUID));
/* We take advantage of the property
* that providing nullptr for the characteristic callback results in
* characteristic discovery being skipped for each matching
@ -1112,6 +1162,7 @@ ble_error_t GattClient::discoverServices(
GattAttribute::Handle_t endHandle
)
{
tr_warning("discoverServices based on handle range not implemented");
return BLE_ERROR_NOT_IMPLEMENTED;
}
@ -1132,6 +1183,7 @@ bool GattClient::isServiceDiscoveryActive() const
void GattClient::terminateServiceDiscovery()
{
tr_info("Terminate service discovery");
ProcedureControlBlock *pcb = control_blocks;
while (pcb) {
if (pcb->type == COMPLETE_DISCOVERY_PROCEDURE) {
@ -1150,6 +1202,7 @@ ble_error_t GattClient::read(
{
// verify that there is no other procedures going on this connection
if (_is_reseting || get_control_block(connection_handle)) {
tr_error("cannot launch attribute read");
return BLE_ERROR_INVALID_STATE;
}
@ -1160,6 +1213,7 @@ ble_error_t GattClient::read(
);
if (read_pcb == nullptr) {
tr_error("Attribute read failed due to allocation error");
return BLE_ERROR_NO_MEM;
}
@ -1167,6 +1221,8 @@ ble_error_t GattClient::read(
ble_error_t err = BLE_ERROR_NONE;
tr_debug("Connection %d - read attribute %d offset %d", connection_handle, attribute_handle, offset);
if (offset == 0) {
err = _pal_client.read_attribute_value(
connection_handle, attribute_handle
@ -1178,6 +1234,7 @@ ble_error_t GattClient::read(
}
if (err) {
tr_error("Attribute read failed due %s", ble_error_to_string(err));
remove_control_block(read_pcb);
delete read_pcb;
}
@ -1195,9 +1252,12 @@ ble_error_t GattClient::write(
) const
{
if (_is_reseting || get_control_block(connection_handle)) {
tr_error("cannot launch attibute write");
return BLE_ERROR_INVALID_STATE;
}
tr_debug("Connection %d - write attribute %d value %s", connection_handle, attribute_handle, tr_array(value, length));
uint16_t mtu = get_mtu(connection_handle);
#if BLE_FEATURE_SIGNING
@ -1218,6 +1278,7 @@ ble_error_t GattClient::write(
#endif // BLE_FEATURE_SIGNING
if (cmd == GATT_OP_WRITE_CMD) {
if (length > (uint16_t) (mtu - WRITE_HEADER_LENGTH)) {
tr_error("Writes need to fit in a single message");
return BLE_ERROR_PARAM_OUT_OF_RANGE;
}
return _pal_client.write_without_response(
@ -1228,6 +1289,7 @@ ble_error_t GattClient::write(
#if BLE_FEATURE_SIGNING
} else if (cmd == GATT_OP_SIGNED_WRITE_CMD) {
if (length > (uint16_t) (mtu - WRITE_HEADER_LENGTH - CMAC_LENGTH - MAC_COUNTER_LENGTH)) {
tr_error("Signed writes need to fit in single message");
return BLE_ERROR_PARAM_OUT_OF_RANGE;
}
ble_error_t status = _pal_client.signed_write_without_response(
@ -1247,6 +1309,7 @@ ble_error_t GattClient::write(
if (length > (uint16_t) (mtu - WRITE_HEADER_LENGTH)) {
data = (uint8_t *) malloc(length);
if (data == nullptr) {
tr_err("Write failed due to allocation error");
return BLE_ERROR_NO_MEM;
}
memcpy(data, value, length);
@ -1261,6 +1324,7 @@ ble_error_t GattClient::write(
if (write_pcb == nullptr) {
free(data);
tr_err("Write failed due to allocation error");
return BLE_ERROR_NO_MEM;
}
@ -1283,6 +1347,7 @@ ble_error_t GattClient::write(
}
if (err) {
tr_error("Write request failed due to %s", ble_error_to_string(err));
remove_control_block(write_pcb);
delete write_pcb;
}
@ -1298,6 +1363,7 @@ void GattClient::onServiceDiscoveryTermination(
ServiceDiscovery::TerminationCallback_t callback
)
{
tr_info("Service discovery ended");
_termination_callback = callback;
}
@ -1308,6 +1374,8 @@ ble_error_t GattClient::discoverCharacteristicDescriptors(
const CharacteristicDescriptorDiscovery::TerminationCallback_t &terminationCallback
)
{
tr_info("Discover char descriptors %d", characteristic.getDeclHandle());
// verify that there is no other procedures going on this connection
if (_is_reseting || get_control_block(characteristic.getConnectionHandle())) {
return BLE_ERROR_INVALID_STATE;
@ -1370,6 +1438,7 @@ void GattClient::terminateCharacteristicDescriptorDiscovery(
const DiscoveredCharacteristic &characteristic
)
{
tr_info("terminate char descriptor discovery %d", characteristic.getDeclHandle());
ProcedureControlBlock *pcb = control_blocks;
while (pcb) {
@ -1397,6 +1466,7 @@ ble_error_t GattClient::negotiateAttMtu(
ble_error_t GattClient::reset()
{
tr_info("GattClient reset");
/* Notify that the instance is about to shut down. */
shutdownCallChain.call(&ble::BLE::Instance().gattClient());
shutdownCallChain.clear();
@ -1434,6 +1504,7 @@ void GattClient::on_att_mtu_change(
uint16_t att_mtu_size
)
{
tr_info("MTU changed to %d", att_mtu_size);
if (eventHandler) {
eventHandler->onAttMtuChange(connection_handle, att_mtu_size);
}
@ -1471,6 +1542,7 @@ void GattClient::on_server_message_received(
const AttServerMessage &message
)
{
tr_debug("Received server message %s", attribute_opcode_to_string(message.opcode));
switch (message.opcode) {
case AttributeOpcode::ERROR_RESPONSE:
case AttributeOpcode::EXCHANGE_MTU_RESPONSE:
@ -1493,6 +1565,7 @@ void GattClient::on_server_message_received(
} break;
default:
tr_warning("Unhandled message in gatt client received from server");
// invalid message receive
return;
}
@ -1527,6 +1600,7 @@ void GattClient::on_server_event(connection_handle_t connection, const AttServer
callbacks_params.type = BLE_HVX_NOTIFICATION;
callbacks_params.len = notification.attribute_value.size();
callbacks_params.data = notification.attribute_value.data();
tr_debug("Notification for char: %d value: %s", notification.attribute_handle, tr_array(notification.attribute_value.data(), notification.attribute_value.size()));
} break;
case AttributeOpcode::HANDLE_VALUE_INDICATION: {
@ -1536,9 +1610,11 @@ void GattClient::on_server_event(connection_handle_t connection, const AttServer
callbacks_params.type = BLE_HVX_INDICATION;
callbacks_params.len = indication.attribute_value.size();
callbacks_params.data = indication.attribute_value.data();
tr_debug("Indication for char: %d value: %s", indication.attribute_handle, tr_array(indication.attribute_value.data(), indication.attribute_value.size()));
} break;
default:
tr_warning("Unhandled event in gatt client received from server");
return;
}
@ -1633,6 +1709,9 @@ uint16_t GattClient::get_mtu(connection_handle_t connection) const
*/
void GattClient::setEventHandler(EventHandler *handler)
{
if (!handler) {
tr_warning("Setting a null gatt event handler");
}
eventHandler = handler;
}
@ -1705,6 +1784,11 @@ GattClient::HVXCallbackChain_t &GattClient::onHVX()
*/
void GattClient::processReadResponse(const GattReadCallbackParams *params)
{
if (params->status == BLE_ERROR_NONE) {
tr_debug("Att read complete handle 0x%x (offset %d), value %s", params->handle, params->offset, tr_array(params->data, params->len));
} else {
tr_info("Connection %d - Att read failed with error %s", params->connHandle, ble_error_to_string(params->status));
}
onDataReadCallbackChain(params);
}
@ -1713,6 +1797,11 @@ void GattClient::processReadResponse(const GattReadCallbackParams *params)
*/
void GattClient::processWriteResponse(const GattWriteCallbackParams *params)
{
if (params->status == BLE_ERROR_NONE) {
tr_debug("Att write complete handle 0x%x", params->handle);
} else {
tr_info("Connection %d - Att write failed with error %s", params->connHandle, ble_error_to_string(params->status));
}
onDataWriteCallbackChain(params);
}