From f4febdcb9df0a7c52ae31e14e0856c05421f8657 Mon Sep 17 00:00:00 2001 From: Abbas Bracken Ziad Date: Mon, 25 Jan 2021 10:58:41 +0000 Subject: [PATCH] Add tracing to BLE GAP (#14117) * Add traces to GapImpl.cpp * Add helpers and param logs * Update GapImpl.cpp * Move helpers to ble_trace_helpers.h * Add traces to whitelist setter & getter functions * Prepend parent dir. to ble_trace_helpers.h include line * Resolve portability issue by using PRI* macro in place of %lu * Add traces to PalGapImpl.cpp * Complete PAL GAP traces * Remove stray include * Make 'echo' traces in PAL configurable Some of the tr_info traces at the beginning of PAL functions are duplicates ('echoes') of those in GAP functions. This commit enables including/excluding of these traces in mbed_app.json by writing 1/0, respectively to the MBED_CONF_CORDIO_TRACE_PAL_ECHOES config macro. The default is to exclude 'echo' traces. * Add missing spaces in tr_info traces * Clean-up param log for set_extended_advertising_parameters * Remove "Failed: " from every tr_error trace * Apply changes from PalGapImpl.cpp review * Apply changes from GapImpl.cpp review * Use binary for channel map trace B0: ADVERTISING_CHANNEL_37 B1: ADVERTISING_CHANNEL_38 B2: ADVERTISING_CHANNEL_39 We're assuming that the user understands the above. This could be documented somewhere. * Replace more %lu w/PRIu32 * Add tr_info to terminateSync for user call * Make trace group for PAL traces BLDM * Remove [PAL] prefix from every PAL trace * Add trace to setPeripheralPrivacyConfiguration * Make set scan params tr_info dependent on selected PHY * Add trace to GAP events * Other GAP events required traces --- .../source/common/ble_trace_helpers.h | 466 +++++++++++++ .../FEATURE_BLE/source/cordio/mbed_lib.json | 4 + .../source/cordio/source/PalGapImpl.cpp | 373 ++++++++++- .../FEATURE_BLE/source/generic/GapImpl.cpp | 630 +++++++++++++++++- 4 files changed, 1465 insertions(+), 8 deletions(-) diff --git a/connectivity/FEATURE_BLE/source/common/ble_trace_helpers.h b/connectivity/FEATURE_BLE/source/common/ble_trace_helpers.h index 26092a4f18..8059361a00 100644 --- a/connectivity/FEATURE_BLE/source/common/ble_trace_helpers.h +++ b/connectivity/FEATURE_BLE/source/common/ble_trace_helpers.h @@ -21,6 +21,7 @@ #include "ble/SecurityManager.h" #include "mbed-trace/mbed_trace.h" #include "pal/GapTypes.h" +#include "pal/GapEvents.h" #include "ble-host/include/dm_api.h" #include "common/UUID.h" @@ -226,6 +227,471 @@ static inline const char *to_string(privacy_mode_t mode) } } +static inline const char* to_string(ble::advertising_type_t advType) +{ + switch (advType.value()) { + case ble::advertising_type_t::CONNECTABLE_UNDIRECTED: + return "CONNECTABLE_UNDIRECTED"; + case ble::advertising_type_t::CONNECTABLE_DIRECTED: + return "CONNECTABLE_DIRECTED"; + case ble::advertising_type_t::SCANNABLE_UNDIRECTED: + return "SCANNABLE_UNDIRECTED"; + case ble::advertising_type_t::NON_CONNECTABLE_UNDIRECTED: + return "NON_CONNECTABLE_UNDIRECTED"; + case ble::advertising_type_t::CONNECTABLE_DIRECTED_LOW_DUTY: + return "CONNECTABLE_DIRECTED_LOW_DUTY"; + case ble::advertising_type_t::CONNECTABLE_NON_SCANNABLE_UNDIRECTED: + return "CONNECTABLE_NON_SCANNABLE_UNDIRECTED"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::own_address_type_t addressType) +{ + switch (addressType.value()) { + case ble::own_address_type_t::PUBLIC: + return "PUBLIC"; + case ble::own_address_type_t::RANDOM: + return "RANDOM"; + case ble::own_address_type_t::RESOLVABLE_PRIVATE_ADDRESS_PUBLIC_FALLBACK: + return "RESOLVABLE_PRIVATE_ADDRESS_PUBLIC_FALLBACK"; + case ble::own_address_type_t::RESOLVABLE_PRIVATE_ADDRESS_RANDOM_FALLBACK: + return "RESOLVABLE_PRIVATE_ADDRESS_RANDOM_FALLBACK"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::advertising_filter_policy_t policy) +{ + switch (policy.value()) { + case ble::advertising_filter_policy_t::NO_FILTER: + return "NO_FILTER"; + case ble::advertising_filter_policy_t::FILTER_SCAN_REQUESTS: + return "FILTER_SCAN_REQUESTS"; + case ble::advertising_filter_policy_t::FILTER_CONNECTION_REQUEST: + return "FILTER_CONNECTION_REQUEST"; + case ble::advertising_filter_policy_t::FILTER_SCAN_AND_CONNECTION_REQUESTS: + return "FILTER_SCAN_AND_CONNECTION_REQUESTS"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::phy_t phy) +{ + switch (phy.value()) { + case ble::phy_t::NONE: + return "NONE"; + case ble::phy_t::LE_1M: + return "LE_1M"; + case ble::phy_t::LE_2M: + return "LE_2M"; + case ble::phy_t::LE_CODED: + return "LE_CODED"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::scanning_filter_policy_t policy) +{ + switch (policy.value()) { + case ble::scanning_filter_policy_t::NO_FILTER: + return "NO_FILTER"; + case ble::scanning_filter_policy_t::FILTER_ADVERTISING: + return "FILTER_ADVERTISING"; + case ble::scanning_filter_policy_t::NO_FILTER_INCLUDE_UNRESOLVABLE_DIRECTED: + return "NO_FILTER_INCLUDE_UNRESOLVABLE_DIRECTED"; + case ble::scanning_filter_policy_t::FILTER_ADVERTISING_INCLUDE_UNRESOLVABLE_DIRECTED: + return "FILTER_ADVERTISING_INCLUDE_UNRESOLVABLE_DIRECTED"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::duplicates_filter_t filtering) +{ + switch (filtering.value()) { + case ble::duplicates_filter_t::ENABLE: + return "ENABLE"; + case ble::duplicates_filter_t::DISABLE: + return "DISABLE"; + case ble::duplicates_filter_t::PERIODIC_RESET: + return "PERIODIC_RESET"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::peer_address_type_t addressType) +{ + switch (addressType.value()) { + case ble::peer_address_type_t::PUBLIC: + return "PUBLIC"; + case ble::peer_address_type_t::RANDOM: + return "RANDOM"; + case ble::peer_address_type_t::PUBLIC_IDENTITY: + return "PUBLIC_IDENTITY"; + case ble::peer_address_type_t::RANDOM_STATIC_IDENTITY: + return "RANDOM_STATIC_IDENTITY"; + case ble::peer_address_type_t::ANONYMOUS: + return "ANONYMOUS"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::initiator_filter_policy_t policy) +{ + switch(policy.value()) { + case ble::initiator_filter_policy_t::NO_FILTER: + return "NO_FILTER"; + case ble::initiator_filter_policy_t::USE_WHITE_LIST: + return "USE_WHITE_LIST"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::coded_symbol_per_bit_t sym) +{ + switch (sym.value()) { + case ble::coded_symbol_per_bit_t::UNDEFINED: + return "UNDEFINED"; + case ble::coded_symbol_per_bit_t::S2: + return "S2"; + case ble::coded_symbol_per_bit_t::S8: + return "S8"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::local_disconnection_reason_t reason) +{ + switch (reason.value()) { + case ble::local_disconnection_reason_t::AUTHENTICATION_FAILURE: + return "AUTHENTICATION_FAILURE"; + case ble::local_disconnection_reason_t::USER_TERMINATION: + return "USER_TERMINATION"; + case ble::local_disconnection_reason_t::LOW_RESOURCES: + return "LOW_RESOURCES"; + case ble::local_disconnection_reason_t::POWER_OFF: + return "POWER OFF"; + case ble::local_disconnection_reason_t::UNSUPPORTED_REMOTE_FEATURE: + return "UNSUPPORTED_REMOTE_FEATURE"; + case ble::local_disconnection_reason_t::PAIRING_WITH_UNIT_KEY_NOT_SUPPORTED: + return "PAIRING_WITH_UNIT_KEY_NOT_SUPPORTED"; + case ble::local_disconnection_reason_t::UNACCEPTABLE_CONNECTION_PARAMETERS: + return "UNACCEPTABLE_CONNECTION_PARAMETERS"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::advertising_channel_map_t map) +{ + switch (map.value()) { + case ble::advertising_channel_map_t::ADVERTISING_CHANNEL_37: + return "[001]"; + case ble::advertising_channel_map_t::ADVERTISING_CHANNEL_38: + return "[010]"; + case ble::advertising_channel_map_t::ADVERTISING_CHANNEL_37_AND_38: + return "[011]"; + case ble::advertising_channel_map_t::ADVERTISING_CHANNEL_39: + return "[100]"; + case ble::advertising_channel_map_t::ADVERTISING_CHANNEL_37_AND_39: + return "[101]"; + case ble::advertising_channel_map_t::ADVERTISING_CHANNEL_38_AND_39: + return "[110]"; + case ble::advertising_channel_map_t::ALL_ADVERTISING_CHANNELS: + return "[111]"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::connection_peer_address_type_t connection_peer_address_type) +{ + switch (connection_peer_address_type.value()) { + case ble::connection_peer_address_type_t::PUBLIC_ADDRESS: + return "PUBLIC_ADDRESS"; + case ble::connection_peer_address_type_t::RANDOM_ADDRESS: + return "RANDOM_ADDRESS"; + case ble::connection_peer_address_type_t::PUBLIC_IDENTITY_ADDRESS: + return "PUBLIC_IDENTITY_ADDRESS"; + case ble::connection_peer_address_type_t::RANDOM_IDENTITY_ADDRESS: + return "RANDOM_IDENTITY_ADDRESS"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::whitelist_address_type_t whitelist_address_type) +{ + if (whitelist_address_type.value() == ble::whitelist_address_type_t::PUBLIC_DEVICE_ADDRESS) { + return "PUBLIC_DEVICE_ADDRESS"; + } else { + return "RANDOM_DEVICE_ADDRESS"; + } +} + +static inline const char* to_string(ble::hci_error_code_t error) +{ + switch (error.value()) { + case ble::hci_error_code_t::SUCCESS: + return "SUCCESS"; + case ble::hci_error_code_t::UNKNOWN_HCI_COMMAND: + return "UNKNOWN_HCI_COMMAND"; + case ble::hci_error_code_t::UNKNOWN_CONNECTION_IDENTIFIER: + return "UNKNOWN_CONNECTION_IDENTIFIER"; + case ble::hci_error_code_t::HARDWARE_FAILLURE: + return "HARDWARE_FAILLURE"; + case ble::hci_error_code_t::PAGE_TIMEOUT: + return "PAGE_TIMEOUT"; + case ble::hci_error_code_t::AUTHENTICATION_FAILLURE: + return "AUTHENTICATION_FAILLURE"; + case ble::hci_error_code_t::PIN_OR_KEY_MISSING: + return "PIN_OR_KEY_MISSING"; + case ble::hci_error_code_t::MEMORY_CAPACITY_EXCEEDED: + return "MEMORY_CAPACITY_EXCEEDED"; + case ble::hci_error_code_t::CONNECTION_TIMEOUT: + return "CONNECTION_TIMEOUT"; + case ble::hci_error_code_t::CONNECTION_LIMIT_EXCEEDED: + return "CONNECTION_LIMIT_EXCEEDED"; + case ble::hci_error_code_t::SYNCHRONOUS_CONNECTION_LIMIT_TO_A_DEVICE_EXCEEDED: + return "SYNCHRONOUS_CONNECTION_LIMIT_TO_A_DEVICE_EXCEEDED"; + case ble::hci_error_code_t::CONNECTION_ALREADY_EXIST: + return "CONNECTION_ALREADY_EXIST"; + case ble::hci_error_code_t::COMMAND_DISALLOWED: + return "COMMAND_DISALLOWED"; + case ble::hci_error_code_t::CONNECTION_REJECTED_DUE_TO_LIMITED_RESOURCES: + return "CONNECTION_REJECTED_DUE_TO_LIMITED_RESOURCES"; + case ble::hci_error_code_t::CONNECTION_REJECTED_DUE_TO_SECURITY_REASONS: + return "CONNECTION_REJECTED_DUE_TO_SECURITY_REASONS"; + case ble::hci_error_code_t::CONNECTION_REJECTED_DUE_TO_UNACCEPTABLE_BD_ADDR: + return "CONNECTION_REJECTED_DUE_TO_UNACCEPTABLE_BD_ADDR"; + case ble::hci_error_code_t::CONNECTION_ACCEPT_TIMEOUT_EXCEEDED: + return "CONNECTION_ACCEPT_TIMEOUT_EXCEEDED"; + case ble::hci_error_code_t::UNSUPPORTED_FEATURE_OR_PARAMETER_VALUE: + return "UNSUPPORTED_FEATURE_OR_PARAMETER_VALUE"; + case ble::hci_error_code_t::INVALID_HCI_COMMAND_PARAMETERS: + return "INVALID_HCI_COMMAND_PARAMETERS"; + case ble::hci_error_code_t::REMOTE_USER_TERMINATED_CONNECTION: + return "REMOTE_USER_TERMINATED_CONNECTION"; + case ble::hci_error_code_t::REMOTE_DEVICE_TERMINATED_CONNECTION_DUE_TO_LOW_RESOURCES: + return "REMOTE_DEVICE_TERMINATED_CONNECTION_DUE_TO_LOW_RESOURCES"; + case ble::hci_error_code_t::REMOTE_DEVICE_TERMINATED_CONNECTION_DUE_TO_POWER_OFF: + return "REMOTE_DEVICE_TERMINATED_CONNECTION_DUE_TO_POWER_OFF"; + case ble::hci_error_code_t::CONNECTION_TERMINATED_BY_LOCAL_HOST: + return "CONNECTION_TERMINATED_BY_LOCAL_HOST"; + case ble::hci_error_code_t::REPEATED_ATTEMPTS: + return "REPEATED_ATTEMPTS"; + case ble::hci_error_code_t::PAIRING_NOT_ALLOWED: + return "PAIRING_NOT_ALLOWED"; + case ble::hci_error_code_t::UNKNOWN_LMP_PDU: + return "UNKNOWN_LMP_PDU"; + case ble::hci_error_code_t::UNSUPPORTED_REMOTE_FEATURE | ble::hci_error_code_t::UNSUPPORTED_LMP_FEATURE: + return "UNSUPPORTED_REMOTE_FEATURE/UNSUPPORTED_LMP_FEATURE"; + case ble::hci_error_code_t::SCO_OFFSET_REJECTED: + return "SCO_OFFSET_REJECTED"; + case ble::hci_error_code_t::SCO_INTERVAL_REJECTED: + return "SCO_INTERVAL_REJECTED"; + case ble::hci_error_code_t::SCO_AIR_MODE_REJECTED: + return "SCO_AIR_MODE_REJECTED"; + case ble::hci_error_code_t::INVALID_LMP_PARAMETERS | ble::hci_error_code_t::INVALID_LL_PARAMETERS: + return "INVALID_LMP_PARAMETERS/INVALID_LL_PARAMETERS"; + case ble::hci_error_code_t::UNSPECIFIED_ERROR: + return "UNSPECIFIED_ERROR"; + case ble::hci_error_code_t::UNSUPPORTED_LMP_PARAMETER_VALUE | ble::hci_error_code_t::UNSUPPORTED_LL_PARAMETER_VALUE: + return "UNSUPPORTED_LMP_PARAMETER_VALUE/UNSUPPORTED_LL_PARAMETER_VALUE"; + case ble::hci_error_code_t::ROLE_CHANGE_NOT_ALLOWED: + return "ROLE_CHANGE_NOT_ALLOWED"; + case ble::hci_error_code_t::LMP_RESPONSE_TIMEOUT | ble::hci_error_code_t::LL_RESPONSE_TIMEOUT: + return "LMP_RESPONSE_TIMEOUT/LL_RESPONSE_TIMEOUT"; + case ble::hci_error_code_t::LMP_ERROR_TRANSACTION_COLLISION | ble::hci_error_code_t::LL_PROCEDURE_COLLISION: + return "LMP_ERROR_TRANSACTION_COLLISION/LL_PROCEDURE_COLLISION"; + case ble::hci_error_code_t::LMP_PDU_NOT_ALLOWED: + return "LMP_PDU_NOT_ALLOWED"; + case ble::hci_error_code_t::ENCRYPTION_MODE_NOT_ACCEPTABLE: + return "ENCRYPTION_MODE_NOT_ACCEPTABLE"; + case ble::hci_error_code_t::LINK_KEY_CANNOT_BE_CHANGED: + return "LINK_KEY_CANNOT_BE_CHANGED"; + case ble::hci_error_code_t::REQUESTED_QOS_NOT_SUPPORTED: + return "REQUESTED_QOS_NOT_SUPPORTED"; + case ble::hci_error_code_t::INSTANT_PASSED: + return "INSTANT_PASSED"; + case ble::hci_error_code_t::PAIRING_WITH_UNIT_KEY_NOT_SUPPORTED: + return "PAIRING_WITH_UNIT_KEY_NOT_SUPPORTED"; + case ble::hci_error_code_t::DIFFERENT_TRANSACTION_COLLISION: + return "DIFFERENT_TRANSACTION_COLLISION"; + case ble::hci_error_code_t::RESERVED_FOR_FUTURE_USE: + return "RESERVED_FOR_FUTURE_USE"; + case ble::hci_error_code_t::QOS_UNACCEPTABLE_PARAMETER: + return "QOS_UNACCEPTABLE_PARAMETER"; + case ble::hci_error_code_t::QOS_REJECTED: + return "QOS_REJECTED"; + case ble::hci_error_code_t::CHANNEL_CLASSIFICATION_NOT_SUPPORTED: + return "CHANNEL_CLASSIFICATION_NOT_SUPPORTED"; + case ble::hci_error_code_t::INSUFFICIENT_SECURITY: + return "INSUFFICIENT_SECURITY"; + case ble::hci_error_code_t::PARAMETER_OUT_OF_MANDATORY_RANGE: + return "PARAMETER_OUT_OF_MANDATORY_RANGE"; + case ble::hci_error_code_t::ROLE_SWITCH_PENDING: + return "ROLE_SWITCH_PENDING"; + case ble::hci_error_code_t::RESERVED_SLOT_VIOLATION: + return "RESERVED_SLOT_VIOLATION"; + case ble::hci_error_code_t::ROLE_SWITCH_FAILED: + return "ROLE_SWITCH_FAILED"; + case ble::hci_error_code_t::EXTENDED_INQUIRY_RESPONSE_TOO_LARGE: + return "EXTENDED_INQUIRY_RESPONSE_TOO_LARGE"; + case ble::hci_error_code_t::SECURE_SIMPLE_PAIRING_NOT_SUPPORTED_BY_HOST: + return "SECURE_SIMPLE_PAIRING_NOT_SUPPORTED_BY_HOST"; + case ble::hci_error_code_t::HOST_BUSY_PAIRING: + return "HOST_BUSY_PAIRING"; + case ble::hci_error_code_t::CONNECTION_REJECTED_DUE_TO_NO_SUITABLE_CHANNEL_FOUND: + return "CONNECTION_REJECTED_DUE_TO_NO_SUITABLE_CHANNEL_FOUND"; + case ble::hci_error_code_t::CONTROLLER_BUSY: + return "CONTROLLER_BUSY"; + case ble::hci_error_code_t::UNACCEPTABLE_CONNECTION_PARAMETERS: + return "UNACCEPTABLE_CONNECTION_PARAMETERS"; + case ble::hci_error_code_t::ADVERTISING_TIMEOUT: + return "ADVERTISING_TIMEOUT"; + case ble::hci_error_code_t::CONNECTION_TERMINATED_DUE_TO_MIC_FAILURE: + return "CONNECTION_TERMINATED_DUE_TO_MIC_FAILURE"; + case ble::hci_error_code_t::CONNECTION_FAILED_TO_BE_ESTABLISHED: + return "CONNECTION_FAILED_TO_BE_ESTABLISHED"; + case ble::hci_error_code_t::MAC_CONNECTION_FAILED: + return "MAC_CONNECTION_FAILED"; + case ble::hci_error_code_t::COARSE_CLOCK_ADJUSTMENT_REJECTED_BUT_WILL_TRY_TO_ADJUST_USING_CLOCK_DRAGGING: + return "COARSE_CLOCK_ADJUSTMENT_REJECTED_BUT_WILL_TRY_TO_ADJUST_USING_CLOCK_DRAGGING"; + case ble::hci_error_code_t::TYPE0_SUBMAP_NOT_DEFINED: + return "TYPE0_SUBMAP_NOT_DEFINED"; + case ble::hci_error_code_t::UNKNOWN_ADVERTISING_IDENTIFIER: + return "UNKNOWN_ADVERTISING_IDENTIFIER"; + case ble::hci_error_code_t::LIMIT_REACHED: + return "LIMIT_REACHED"; + case ble::hci_error_code_t::OPERATION_CANCELLED_BY_HOST: + return "OPERATION_CANCELLED_BY_HOST"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::advertising_fragment_description_t fragment_description) +{ + switch (fragment_description.value()) { + case ble::advertising_fragment_description_t::INTERMEDIATE_FRAGMENT: + return "INTERMEDIATE_FRAGMENT"; + case ble::advertising_fragment_description_t::FIRST_FRAGMENT: + return "FIRST_FRAGMENT"; + case ble::advertising_fragment_description_t::LAST_FRAGMENT: + return "LAST_FRAGMENT"; + case ble::advertising_fragment_description_t::COMPLETE_FRAGMENT: + return "COMPLETE_FRAGMENT"; + case ble::advertising_fragment_description_t::UNCHANGED_DATA: + return "UNCHANGED_DATA"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::peripheral_privacy_configuration_t::resolution_strategy_t resolution_strategy) +{ + switch (resolution_strategy) { + case ble::peripheral_privacy_configuration_t::resolution_strategy_t::DO_NOT_RESOLVE: + return "DO_NOT_RESOLVE"; + case ble::peripheral_privacy_configuration_t::resolution_strategy_t::REJECT_NON_RESOLVED_ADDRESS: + return "REJECT_NON_RESOLVED_ADDRESS"; + case ble::peripheral_privacy_configuration_t::resolution_strategy_t::PERFORM_PAIRING_PROCEDURE: + return "PERFORM_PAIRING_PROCEDURE"; + case ble::peripheral_privacy_configuration_t::resolution_strategy_t::PERFORM_AUTHENTICATION_PROCEDURE: + return "PERFORM_AUTHENTICATION_PROCEDURE"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::GapEventType event_type) +{ + switch (event_type.value()) { + case ble::GapEventType::type::UNEXPECTED_ERROR: + return "UNEXPECTED_ERROR"; + case ble::GapEventType::type::CONNECTION_COMPLETE: + return "CONNECTION_COMPLETE"; + case ble::GapEventType::type::ADVERTISING_REPORT: + return "ADVERTISING_REPORT"; + case ble::GapEventType::type::CONNECTION_UPDATE: + return "CONNECTION_UPDATE"; + case ble::GapEventType::type::REMOTE_CONNECTION_PARAMETER_REQUEST: + return "REMOTE_CONNECTION_PARAMETER_REQUEST"; + case ble::GapEventType::type::DISCONNECTION_COMPLETE: + return "DISCONNECTION_COMPLETE"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::received_advertising_type_t type) +{ + switch (type.value()) { + case ble::received_advertising_type_t::ADV_IND: + return "ADV_IND"; + case ble::received_advertising_type_t::ADV_DIRECT_IND: + return "ADV_DIRECT_IND"; + case ble::received_advertising_type_t::ADV_SCAN_IND: + return "ADV_SCAN_IND"; + case ble::received_advertising_type_t::ADV_NONCONN_IND: + return "ADV_NONCONN_IND"; + case ble::received_advertising_type_t::SCAN_RESPONSE: + return "SCAN_RESPONSE"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::connection_role_t role) +{ + if (role.value() == ble::connection_role_t::CENTRAL) { + return "CENTRAL"; + } else { + return "PERIPHERAL"; + } +} + +static inline const char* to_string(ble::direct_address_type_t direct_address_type) +{ + switch (direct_address_type.value()) { + case ble::direct_address_type_t::PUBLIC_ADDRESS: + return "PUBLIC_ADDRESS"; + case ble::direct_address_type_t::RANDOM_ADDRESS: + return "RANDOM_ADDRESS"; + case ble::direct_address_type_t::PUBLIC_IDENTITY_ADDRESS: + return "PUBLIC_IDENTITY_ADDRESS"; + case ble::direct_address_type_t::RANDOM_IDENTITY_ADDRESS: + return "RANDOM_IDENTITY_ADDRESS"; + case ble::direct_address_type_t::RANDOM_DEVICE_ADDRESS: + return "RANDOM_DEVICE_ADDRESS"; + default: + return "unknown"; + } +} + +static inline const char* to_string(ble::advertising_data_status_t data_status) +{ + switch (data_status.value()) { + case ble::advertising_data_status_t::COMPLETE: + return "COMPLETE"; + case ble::advertising_data_status_t::INCOMPLETE_MORE_DATA: + return "INCOMPLETE_MORE_DATA"; + case ble::advertising_data_status_t::INCOMPLETE_DATA_TRUNCATED: + return "INCOMPLETE_DATA_TRUNCATED"; + default: + return "unknown"; + } +} } // namespace ble diff --git a/connectivity/FEATURE_BLE/source/cordio/mbed_lib.json b/connectivity/FEATURE_BLE/source/cordio/mbed_lib.json index 1e19fcda9b..2414204da8 100644 --- a/connectivity/FEATURE_BLE/source/cordio/mbed_lib.json +++ b/connectivity/FEATURE_BLE/source/cordio/mbed_lib.json @@ -82,6 +82,10 @@ "value": null, "macro_name": "CORDIO_RPA_SWAP_WORKAROUND" }, + "trace-pal-echoes": { + "help": "Include 'echo' traces in PAL, i.e. function signature and argument prints", + "value": 0 + }, "trace-hci-packets": { "help": "If tracing is enabled at level DEBUG traces will include HCI packet traces.", "value": false diff --git a/connectivity/FEATURE_BLE/source/cordio/source/PalGapImpl.cpp b/connectivity/FEATURE_BLE/source/cordio/source/PalGapImpl.cpp index 411ea8da64..b7586bd52b 100644 --- a/connectivity/FEATURE_BLE/source/cordio/source/PalGapImpl.cpp +++ b/connectivity/FEATURE_BLE/source/cordio/source/PalGapImpl.cpp @@ -22,10 +22,16 @@ #include "dm_main.h" #include "dm_conn.h" +#include "mbed-trace/mbed_trace.h" +#include "common/ble_trace_helpers.h" + +#define TRACE_GROUP "BLDM" + namespace ble { namespace impl { namespace { + bool dummy_gap_event_handler(const wsfMsgHdr_t *msg) { return false; @@ -102,6 +108,10 @@ address_t PalGap::get_random_address() ble_error_t PalGap::set_random_address(const address_t &address) { + tr_info("Set random address - " + "address=%s", + to_string(address)); + device_random_address = address; DmDevSetRandAddr(const_cast(address.data())); return BLE_ERROR_NONE; @@ -119,6 +129,26 @@ ble_error_t PalGap::set_advertising_parameters( advertising_filter_policy_t advertising_filter_policy ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Set advertising parameters - " + "advertising_interval_min=%d, " + "advertising_interval_max=%d, " + "advertising_type=%s, " + "own_address_type=%s, " + "peer_address_type=%s, " + "peer_address=%s, " + "advertising_channel_map=%s, " + "advertising_filter_policy_t=%s", + advertising_interval_min, + advertising_interval_max, + to_string(advertising_type), + to_string(own_address_type), + to_string(peer_address_type), + to_string(peer_address), + to_string(advertising_channel_map), + to_string(advertising_filter_policy)); +#endif + DmAdvSetInterval( DM_ADV_HANDLE_DEFAULT, advertising_interval_min, @@ -160,6 +190,14 @@ ble_error_t PalGap::set_advertising_data( const advertising_data_t &advertising_data ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Set advertising data - " + "advertising_data_length=%d, " + "advertising_data=%s", + advertising_data_length, + mbed_trace_array(advertising_data.data(), advertising_data_length)); +#endif + DmAdvSetData( DM_ADV_HANDLE_DEFAULT, HCI_ADV_DATA_OP_COMP_FRAG, @@ -170,12 +208,19 @@ ble_error_t PalGap::set_advertising_data( return BLE_ERROR_NONE; } - ble_error_t PalGap::set_scan_response_data( uint8_t scan_response_data_length, const advertising_data_t &scan_response_data ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Set scan response data - " + "scan_response_data_length=%d, " + "scan_response_data=%s", + scan_response_data_length, + mbed_trace_array(scan_response_data.data(), scan_response_data_length)); +#endif + DmAdvSetData( DM_ADV_HANDLE_DEFAULT, HCI_ADV_DATA_OP_COMP_FRAG, @@ -189,6 +234,10 @@ ble_error_t PalGap::set_scan_response_data( ble_error_t PalGap::advertising_enable(bool enable) { + tr_info("Advertising enable - " + "enable=%s", + to_string(enable)); + if (enable) { // The Cordio stack requires to start direct advertising with // the function DmConnAccept instead of the function DmAdvStart. @@ -206,6 +255,7 @@ ble_error_t PalGap::advertising_enable(bool enable) direct_adv_cb->peer_address.data() ); if (direct_adv_cb->connection_handle == DM_CONN_ID_NONE) { + tr_error("unknown ID for pending callback"); return BLE_ERROR_INTERNAL_STACK_FAILURE; } else { direct_adv_cb->state = direct_adv_cb_t::running; @@ -247,6 +297,20 @@ ble_error_t PalGap::set_scan_parameters( scanning_filter_policy_t filter_policy ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Set scan parameters - " + "active_scanning=%s, " + "scan_interval=%d, " + "scan_window=%d, " + "own_address_type=%s, " + "filter_policy=%s", + to_string(active_scanning), + scan_interval, + scan_window, + to_string(own_address_type), + to_string(filter_policy)); +#endif + use_active_scanning = active_scanning; DmScanSetInterval(HCI_INIT_PHY_LE_1M_BIT, &scan_interval, &scan_window); DmScanSetAddrType(own_address_type.value()); @@ -265,6 +329,12 @@ ble_error_t PalGap::scan_enable( bool filter_duplicates ) { + tr_info("Scan enable - " + "enable=%s, " + "filter_duplicates=%s", + to_string(enable), + to_string(filter_duplicates)); + if (enable) { uint8_t scanType = use_active_scanning ? DM_SCAN_TYPE_ACTIVE : DM_SCAN_TYPE_PASSIVE; DmScanStart( @@ -298,6 +368,34 @@ ble_error_t PalGap::create_connection( uint16_t maximum_connection_event_length ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Create Connection - " + "scan_interval=%d, " + "scan_window=%d, " + "initiator_policy=%s, " + "peer_address_type=%s, " + "peer_address=%s, " + "own_address_type=%s, " + "connection_interval_min=%d, " + "connection_interval_max=%d, " + "connection_latency=%d, " + "supervision_timout=%d, " + "minimum_connection_event_length=%d, " + "maximum_connection_event_length=%d", + scan_interval, + scan_window, + to_string(initiator_policy), + to_string(peer_address_type), + to_string(peer_address), + to_string(own_address_type), + connection_interval_min, + connection_interval_max, + connection_latency, + supervision_timeout, + minimum_connection_event_length, + maximum_connection_event_length); +#endif + DmConnSetScanInterval(scan_interval, scan_window); #if BLE_FEATURE_WHITELIST DmDevSetFilterPolicy(DM_FILT_POLICY_MODE_INIT, initiator_policy.value()); @@ -322,6 +420,7 @@ ble_error_t PalGap::create_connection( ); if (connection_id == DM_CONN_ID_NONE) { + tr_error("unknown ID for open connection"); return BLE_ERROR_INTERNAL_STACK_FAILURE; } @@ -368,6 +467,12 @@ ble_error_t PalGap::add_device_to_whitelist( address_t address ) { + tr_info("Add device to whitelist - " + "address_type=%s," + "address=%s", + to_string(address_type), + to_string(address)); + DmDevWhiteListAdd( address_type.value(), const_cast(address.data()) @@ -381,6 +486,12 @@ ble_error_t PalGap::remove_device_from_whitelist( address_t address ) { + tr_info("Remove device from whitelist - " + "address_type=%s, " + "address=%s", + to_string(address_type), + to_string(address)); + DmDevWhiteListRemove( address_type.value(), const_cast(address.data()) @@ -400,7 +511,25 @@ ble_error_t PalGap::connection_parameters_update( uint16_t maximum_connection_event_length ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Connection %d: connection parameters update - " + "connection_interval_min=%d, " + "connection_interval_max=%d, " + "connection_latency=%d, " + "supervision_timeout=%d, " + "minimum_connection_event_length=%d, " + "maximum_connection_event_length=%d", + connection, + connection_interval_min, + connection_interval_max, + connection_latency, + supervision_timeout, + minimum_connection_event_length, + maximum_connection_event_length); +#endif + if (DmConnCheckIdle(connection) != 0) { + tr_error("connection busy"); return BLE_ERROR_INVALID_STATE; } @@ -431,6 +560,21 @@ ble_error_t PalGap::accept_connection_parameter_request( uint16_t maximum_connection_event_length ) { + tr_info("Connection %d: accept connection parameter request - " + "interval_min=%d, " + "interval_max=%d, " + "latency=%d, " + "supervision_timeout=%d, " + "minimum_connection_event_length=%d, " + "maximum_connection_event_length=%d", + connection_handle, + interval_min, + interval_max, + latency, + supervision_timeout, + minimum_connection_event_length, + maximum_connection_event_length); + hciConnSpec_t connection_spec = { interval_min, interval_max, @@ -449,6 +593,11 @@ ble_error_t PalGap::reject_connection_parameter_request( hci_error_code_t rejection_reason ) { + tr_info("Connection %d: reject_connection_parameter_request - " + "rejection_reason=%s", + connection_handle, + to_string(rejection_reason)); + DmRemoteConnParamReqNegReply( connection_handle, rejection_reason.value() @@ -462,6 +611,13 @@ ble_error_t PalGap::disconnect( local_disconnection_reason_t disconnection_reason ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Connection %d: disconnect - " + "disconnection_reason=%s", + connection, + to_string(disconnection_reason)); +#endif + DmConnClose( DM_CLIENT_ID_APP, connection, @@ -475,11 +631,13 @@ ble_error_t PalGap::disconnect( #if BLE_FEATURE_PHY_MANAGEMENT ble_error_t PalGap::read_phy(connection_handle_t connection) { + tr_info("Connection %d: read phy", connection); if (is_feature_supported(controller_supported_features_t::LE_2M_PHY) || is_feature_supported(controller_supported_features_t::LE_CODED_PHY)) { DmReadPhy(connection); return BLE_ERROR_NONE; } + tr_error("Only 1M PHY supported"); return BLE_ERROR_NOT_IMPLEMENTED; } @@ -488,6 +646,14 @@ ble_error_t PalGap::set_preferred_phys( const phy_set_t &rx_phys ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Set preferred phys -" + "tx_phys=%s, " + "rx_phys=%s", + to_string(tx_phys), + to_string(rx_phys)); +#endif + DmSetDefaultPhy( create_all_phys_value(tx_phys, rx_phys), tx_phys.value(), @@ -505,6 +671,17 @@ ble_error_t PalGap::set_phy( coded_symbol_per_bit_t coded_symbol ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Connection %d: set phy - " + "tx_phys=%s, " + "rx_phys=%s, " + "coded_symbol=%s", + connection, + to_string(tx_phys), + to_string(rx_phys), + to_string(coded_symbol)); +#endif + /* if phy set is empty set corresponding all_phys bit to 1 */ uint8_t all_phys = 0; if (tx_phys.value() == 0) { @@ -869,6 +1046,11 @@ ble_error_t PalGap::set_advertising_set_random_address( const address_t &address ) { + tr_info("Advertising set %d: set random address - " + "address=%s", + advertising_handle, + to_string(address)); + DmAdvSetRandAddr(advertising_handle, address.data()); return BLE_ERROR_NONE; } @@ -891,15 +1073,57 @@ ble_error_t PalGap::set_extended_advertising_parameters( bool scan_request_notification ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Advertising set %d: set extended advertising parameters - " + "event_properties:[%s%s%s%s%s%s%s ], " + "primary_advertising_interval_min=%" PRIu32 ", " + "primary_advertising_interval_max=%" PRIu32 ", " + "primary_advertising_channel_map=%s, " + "own_address_type=%s, " + "peer_address_type=%s, " + "peer_address=%s, " + "advertising_filter_policy=%s, " + "advertising_power=%d, " + "primary_advertising_phy=%s, " + "secondary_advertising_max_skip=%d, " + "secondary_phy=%s, " + "advertising_sid=%d, " + "scan_request_notification=%s", + advertising_handle, + event_properties.connectable ? " connectable" : "", + event_properties.scannable ? " scannable" : "", + event_properties.directed ? " directed" : "", + event_properties.high_duty_cycle ? " high_duty_cycle" : "", + event_properties.use_legacy_pdu ? " use_legacy_pdu" : "", + event_properties.omit_advertiser_address ? " omit_advertiser_address," : "", + event_properties.include_tx_power ? " nclude_tx_power" : "", + primary_advertising_interval_min, + primary_advertising_interval_max, + to_string(primary_advertising_channel_map), + to_string(own_address_type), + to_string(peer_address_type), + to_string(peer_address), + to_string(advertising_filter_policy), + advertising_power, + to_string(primary_advertising_phy), + secondary_advertising_max_skip, + to_string(secondary_phy), + advertising_sid, + to_string(scan_request_notification)); +#endif + uint8_t adv_type; if (event_properties.use_legacy_pdu) { if (event_properties.directed == false) { + tr_info("Legacy PDU w/undirected advertising event"); if (event_properties.high_duty_cycle) { + tr_error("cannot use high duty cycle"); return BLE_ERROR_INVALID_PARAM; } if (event_properties.connectable && event_properties.scannable == false) { + tr_error("must be scannable if connectable"); return BLE_ERROR_INVALID_PARAM; } @@ -911,11 +1135,14 @@ ble_error_t PalGap::set_extended_advertising_parameters( adv_type = DM_ADV_NONCONN_UNDIRECT; } } else { + tr_info("Legacy PDU w/directed advertising event"); if (event_properties.scannable) { + tr_error("cannot be scannable"); return BLE_ERROR_INVALID_PARAM; } if (event_properties.connectable == false) { + tr_error("must be connectable"); return BLE_ERROR_INVALID_PARAM; } @@ -927,7 +1154,9 @@ ble_error_t PalGap::set_extended_advertising_parameters( } } else { if (event_properties.directed == false) { + tr_info("Extended PDU w/undirected advertising event"); if (event_properties.high_duty_cycle) { + tr_error("cannot use high duty cycle"); return BLE_ERROR_INVALID_PARAM; } @@ -946,6 +1175,7 @@ ble_error_t PalGap::set_extended_advertising_parameters( // standpoint if (event_properties.connectable && event_properties.scannable) { + tr_error("cannot be scannable if connectable"); return BLE_ERROR_INVALID_PARAM; } else if (event_properties.connectable) { if (event_properties.high_duty_cycle) { @@ -1022,6 +1252,17 @@ ble_error_t PalGap::set_periodic_advertising_parameters( bool advertise_power ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Advertising set %d: set periodic advertising parameters - " + "periodic_advertising_min=%s, " + "periodic_advertising_max=%s, " + "advertise_power=%s", + advertising_handle, + to_string(periodic_advertising_min), + to_string(periodic_advertising_max), + to_string(advertise_power)); +#endif + DmPerAdvIncTxPwr(advertising_handle, advertise_power); DmPerAdvSetInterval( advertising_handle, @@ -1043,6 +1284,19 @@ ble_error_t PalGap::set_extended_advertising_data( const uint8_t *advertising_data ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Advertising set %d: set extended advertising data - " + "operation=%s, " + "minimize_fragmentation=%s, " + "advertising_data_size=%d, " + "advertising_data=%s", + advertising_handle, + to_string(operation), + to_string(minimize_fragmentation), + advertising_data_size, + mbed_trace_array(advertising_data, advertising_data_size)); +#endif + uint8_t frag_pref = minimize_fragmentation ? HCI_ADV_DATA_FRAG_PREF_NO_FRAG : HCI_ADV_DATA_FRAG_PREF_FRAG; @@ -1068,6 +1322,17 @@ ble_error_t PalGap::set_periodic_advertising_data( const uint8_t *advertising_data ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Advertising set %d: set periodic advertising data - " + "fragment_description=%s, " + "advertising_data_size=%d, " + "advertising_data=%s", + advertising_handle, + to_string(fragment_description), + advertising_data_size, + mbed_trace_array(advertising_data, advertising_data_size)); +#endif + DmPerAdvSetData( advertising_handle, fragment_description.value(), @@ -1087,6 +1352,19 @@ ble_error_t PalGap::set_extended_scan_response_data( const uint8_t *scan_response_data ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Advertising data %d: set extended scan response data - " + "operation=%s, " + "minimize_fragmentation=%s, " + "scan_response_data_size=%d, " + "scan_response_data=%s", + advertising_handle, + to_string(operation), + to_string(minimize_fragmentation), + scan_response_data_size, + mbed_trace_array(scan_response_data, scan_response_data_size)); +#endif + uint8_t frag_pref = minimize_fragmentation ? HCI_ADV_DATA_FRAG_PREF_NO_FRAG : HCI_ADV_DATA_FRAG_PREF_FRAG; @@ -1112,7 +1390,14 @@ ble_error_t PalGap::extended_advertising_enable( const uint8_t *in_max_extended_advertising_events ) { + tr_info("Extended advertising enable - " + "enable=%s, " + "number_of_sets=%d", + to_string(enable), + number_of_sets); + if (number_of_sets > DM_NUM_ADV_SETS) { + tr_error("number of sets cannot be greater than %d", DM_NUM_ADV_SETS); return BLE_ERROR_INVALID_PARAM; } @@ -1143,6 +1428,7 @@ ble_error_t PalGap::extended_advertising_enable( direct_adv_cb->peer_address.data() ); if (direct_adv_cb->connection_handle == DM_CONN_ID_NONE) { + tr_error("unknown connection ID %d", direct_adv_cb->connection_handle); return BLE_ERROR_INTERNAL_STACK_FAILURE; } else { direct_adv_cb->state = direct_adv_cb_t::running; @@ -1201,6 +1487,11 @@ ble_error_t PalGap::periodic_advertising_enable( advertising_handle_t advertising_handle ) { + tr_info("Advertising set %d: periodic advertsing enable - " + "enable=%s", + advertising_handle, + to_string(enable)); + if (enable) { DmPerAdvStart(advertising_handle); } else { @@ -1265,6 +1556,16 @@ ble_error_t PalGap::set_extended_scan_parameters( const uint16_t *scan_window ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Set extended scan parameters - " + "own_address_type=%s, " + "filter_policy=%s, " + "scanning_phys=%s", + to_string(own_address_type), + to_string(filter_policy), + to_string(scanning_phys)); +#endif + DmScanSetAddrType(own_address_type.value()); for (size_t i = 0, count = scanning_phys.count(); i < count; ++i) { @@ -1299,6 +1600,16 @@ ble_error_t PalGap::extended_scan_enable( uint16_t period ) { + tr_info("Extended scan enable - " + "enable=%s, " + "filter_duplicates=%s, " + "duration=%d, " + "period=%d", + to_string(enable), + to_string(filter_duplicates), + duration, + period); + if (enable) { uint32_t duration_ms = duration * 10; @@ -1330,6 +1641,20 @@ ble_error_t PalGap::periodic_advertising_create_sync( uint16_t sync_timeout ) { + tr_info("Periodic advertising create sync - " + "use_periodic_advertiser_list=%s, " + "advertising_sid=%d, " + "peer_address_type=%s, " + "peer_address=%s, " + "allowed_skip=%d, " + "sync_timeout=%d", + to_string(use_periodic_advertiser_list), + advertising_sid, + to_string(peer_address_type), + to_string(peer_address), + allowed_skip, + sync_timeout); + DmDevSetExtFilterPolicy( DM_ADV_HANDLE_DEFAULT, DM_FILT_POLICY_MODE_SYNC, @@ -1345,6 +1670,7 @@ ble_error_t PalGap::periodic_advertising_create_sync( ); if (sync_id == DM_SYNC_ID_NONE) { + tr_error("unknown sync ID %d", sync_id); return BLE_ERROR_INTERNAL_STACK_FAILURE; } else { /* this is not the real handle, this is CORDIO internal handle but the user doesn't need to know that */ @@ -1375,6 +1701,16 @@ ble_error_t PalGap::add_device_to_periodic_advertiser_list( uint8_t advertising_sid ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Add device to periodic advertiser list - " + "advertiser_address_type=%s, " + "advertiser_address=%s, " + "advertiser_sid=%d", + to_string(advertiser_address_type), + to_string(advertiser_address), + advertising_sid); +#endif + DmAddDeviceToPerAdvList( advertiser_address_type.value(), const_cast(advertiser_address.data()), @@ -1390,6 +1726,16 @@ ble_error_t PalGap::remove_device_from_periodic_advertiser_list( uint8_t advertising_sid ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Remove device from periodic advertiser list - " + "advertiser_address_type=%s, " + "advertiser_address=%s, " + "advertiser_sid=%d", + to_string(advertiser_address_type), + to_string(advertiser_address), + advertising_sid); +#endif + DmRemoveDeviceFromPerAdvList( advertiser_address_type.value(), const_cast(advertiser_address.data()), @@ -1430,6 +1776,20 @@ ble_error_t PalGap::extended_create_connection( const uint16_t *maximum_connection_event_lengths ) { +#if MBED_CONF_CORDIO_TRACE_PAL_ECHOES + tr_info("Extended create connection - " + "initiator_policy=%s, " + "own_address_type=%s, " + "peer_address_type=%s, " + "peer_address=%s, " + "initiating_phys=%s", + to_string(initiator_policy), + to_string(own_address_type), + to_string(peer_address_type), + to_string(peer_address), + to_string(initiating_phys)); +#endif + DmExtConnSetScanInterval( initiating_phys.value(), const_cast(scan_intervals), @@ -1476,10 +1836,20 @@ ble_error_t PalGap::update_direct_advertising_parameters( advertising_peer_address_type_t peer_address_type ) { + tr_info("Advertising set %d: update direct advertising parameters - " + "advertising_type=%d, " + "peer_address=%s, " + "peer_address_type=%s", + advertising_handle, + advertising_type, + to_string(peer_address), + to_string(peer_address_type)); + // The case where a direct advertising is running and parameters are updated // is considered to be a programming error. User should stop advertising first. direct_adv_cb_t *running = get_running_direct_adv_cb(advertising_handle); if (running) { + tr_error("trying to update parameters but direct advertising is running"); return BLE_ERROR_INVALID_STATE; } @@ -1506,6 +1876,7 @@ ble_error_t PalGap::update_direct_advertising_parameters( advertising_type == DM_ADV_CONN_DIRECT_LO_DUTY) { direct_adv_cb_t *adv_cb = get_free_direct_adv_cb(); if (!adv_cb) { + tr_error("failed to acquire a cb"); return BLE_ERROR_INTERNAL_STACK_FAILURE; } adv_cb->state = direct_adv_cb_t::pending; diff --git a/connectivity/FEATURE_BLE/source/generic/GapImpl.cpp b/connectivity/FEATURE_BLE/source/generic/GapImpl.cpp index 12b97cf902..453b0172f4 100644 --- a/connectivity/FEATURE_BLE/source/generic/GapImpl.cpp +++ b/connectivity/FEATURE_BLE/source/generic/GapImpl.cpp @@ -32,6 +32,10 @@ #include "source/pal/PalEventQueue.h" #include "source/pal/PalSecurityManager.h" +#include "mbed-trace/mbed_trace.h" +#include "common/ble_trace_helpers.h" + +#define TRACE_GROUP "BLGP" // Cordio defines the random address used by connection to be the global one #define CORDIO_GLOBAL_RANDOM_ADDRESS_FOR_CONNECTION 1 @@ -448,6 +452,12 @@ ble_error_t Gap::getAddress( address_t &address ) { + tr_info("Get address - " + "type=%s, " + "address=%s", + to_string(type), + to_string(address)); + type = _address_type; if (_address_type == own_address_type_t::PUBLIC) { @@ -485,9 +495,11 @@ ble_error_t Gap::getRandomAddressType( #if BLE_ROLE_OBSERVER ble_error_t Gap::stopScan() { + tr_info("Stop scan"); ble_error_t err; if (_initiating) { + tr_error("stack busy"); return BLE_STACK_BUSY; } @@ -522,6 +534,38 @@ ble_error_t Gap::connect( const ConnectionParameters &connectionParams ) { + tr_info("Connect - " + "peerAddressType=%s, " + "peerAddress=%s, " + "_filterPolicy=%s, " + "_ownAddressType=%s, ", + to_string(peerAddressType), + to_string(peerAddress), + to_string(connectionParams.getFilter()), + to_string(connectionParams.getOwnAddressType())); + + // Trace connection params for each enabled PHY + for (size_t i = 0; i < connectionParams.getPhySet().count(); ++i) { + tr_info("PHY %d - " + "_scanInterval=%" PRIu32 "ms, " + "_scanWindow=%" PRIu32 "ms, " + "_minConnectionInterval=%" PRIu32 "ms, " + "_maxConnectionInterval=%" PRIu32 "ms, " + "_slaveLatency=%u, " + "_connectionSupervisionTimeout=%" PRIu32 "ms, " + "_minEventLength=%" PRIu32 "ms, " + "_maxEventLength=%" PRIu32 "ms", + i, + scan_interval_t(connectionParams.getScanIntervalArray()[i]).valueInMs(), + scan_window_t(connectionParams.getScanWindowArray()[i]).valueInMs(), + conn_interval_t(connectionParams.getMinConnectionIntervalArray()[i]).valueInMs(), + conn_interval_t(connectionParams.getMaxConnectionIntervalArray()[i]).valueInMs(), + slave_latency_t(connectionParams.getSlaveLatencyArray()[i]).value(), + supervision_timeout_t(connectionParams.getConnectionSupervisionTimeoutArray()[i]).valueInMs(), + conn_event_length_t(connectionParams.getMinEventLengthArray()[i]).valueInMs(), + conn_event_length_t(connectionParams.getMaxEventLengthArray()[i]).valueInMs()); + } + #if BLE_GAP_HOST_BASED_PRIVATE_ADDRESS_RESOLUTION if (_connect_to_host_resolved_address_state == ConnectionToHostResolvedAddressState::scan) { return BLE_ERROR_OPERATION_NOT_PERMITTED; @@ -529,10 +573,12 @@ ble_error_t Gap::connect( #endif // BLE_GAP_HOST_BASED_PRIVATE_ADDRESS_RESOLUTION if (!connectionParams.getNumberOfEnabledPhys()) { + tr_error("no enabled PHY"); return BLE_ERROR_INVALID_PARAM; } if (peerAddressType == peer_address_type_t::ANONYMOUS) { + tr_error("peer address type cannot be anonymous"); return BLE_ERROR_INVALID_PARAM; } @@ -543,6 +589,9 @@ ble_error_t Gap::connect( slave_latency_t(connectionParams.getSlaveLatencyArray()[i]) ) ) { + tr_error("supervision timout cannot be less than/equal to %" PRIu32 "ms", minSupervisionTimeout( + conn_interval_t(connectionParams.getMaxConnectionIntervalArray()[i]), + slave_latency_t(connectionParams.getSlaveLatencyArray()[i])).valueInMs()); return BLE_ERROR_INVALID_PARAM; } } @@ -550,6 +599,7 @@ ble_error_t Gap::connect( // get the random address to set, if not valid, report the error const address_t *address = get_random_address(controller_operation_t::initiating); if (!address) { + tr_error("could not get random address"); return BLE_ERROR_INVALID_STATE; } @@ -583,6 +633,7 @@ ble_error_t Gap::connect( if (is_extended_advertising_available() == false) { phy_set_t set(connectionParams.getPhySet()); if (set.count() != 1 || set.get_1m() == false) { + tr_error("use 1 PHY w/legacy advertising"); return BLE_ERROR_INVALID_PARAM; } @@ -668,6 +719,8 @@ ble_error_t Gap::connect( if (ret == BLE_ERROR_NONE) { _initiating = true; + } else { + tr_error("PAL could not create connection"); } return ret; } @@ -694,7 +747,24 @@ ble_error_t Gap::updateConnectionParameters( conn_event_length_t maxConnectionEventLength ) { + tr_info("Connection %d: update connection paramters - " + "minConnectionInterval=%" PRIu32 "ms, " + "maxConnectionInterval=%" PRIu32 "ms, " + "slaveLatency=%u," + "supervisionTimeout=%" PRIu32 "ms, " + "minConnectionEventLength=%" PRIu32 "ms, " + "maxConnectionEventLength=%" PRIu32 "ms", + connectionHandle, + minConnectionInterval.valueInMs(), + maxConnectionInterval.valueInMs(), + slaveLatency.value(), + supervisionTimeout.valueInMs(), + minConnectionInterval.valueInMs(), + minConnectionInterval.valueInMs()); + if (supervisionTimeout <= minSupervisionTimeout(maxConnectionInterval, slaveLatency)) { + tr_error("supervision timeout cannot be less than/equal to %" PRIu32 "ms", + minSupervisionTimeout(maxConnectionInterval, slaveLatency).valueInMs()); return BLE_ERROR_INVALID_PARAM; } @@ -719,7 +789,24 @@ ble_error_t Gap::acceptConnectionParametersUpdate( conn_event_length_t maxConnectionEventLength ) { + tr_info("Connection %d: accept connection paramater update - " + "minConnectionInterval=%" PRIu32 "ms, " + "maxConnectionInterval=%" PRIu32 "ms, " + "slaveLatency=%u," + "supervisionTimeout=%" PRIu32 "ms, " + "minConnectionEventLength=%" PRIu32 "ms, " + "minConnectionEventLength=%" PRIu32 "ms", + connectionHandle, + minConnectionInterval.valueInMs(), + maxConnectionInterval.valueInMs(), + slaveLatency.value(), + supervisionTimeout.valueInMs(), + minConnectionEventLength.valueInMs(), + maxConnectionEventLength.valueInMs()); + if (supervisionTimeout <= minSupervisionTimeout(maxConnectionInterval, slaveLatency)) { + tr_error("supervision timeout cannot be less than/equal to %" PRIu32 "ms", + minSupervisionTimeout(maxConnectionInterval, slaveLatency).valueInMs()); return BLE_ERROR_INVALID_PARAM; } @@ -748,6 +835,7 @@ ble_error_t Gap::rejectConnectionParametersUpdate( #if BLE_ROLE_CENTRAL ble_error_t Gap::cancelConnect() { + tr_info("Cancel connect"); #if BLE_GAP_HOST_BASED_PRIVATE_ADDRESS_RESOLUTION if (_connect_to_host_resolved_address_state == ConnectionToHostResolvedAddressState::scan) { connecting_to_host_resolved_address_failed(false); @@ -757,6 +845,7 @@ ble_error_t Gap::cancelConnect() #endif // BLE_GAP_HOST_BASED_PRIVATE_ADDRESS_RESOLUTION if (!_initiating) { + tr_error("Failed to cancel connect: stack busy"); return BLE_ERROR_NONE; } @@ -779,6 +868,12 @@ ble_error_t Gap::setPreferredPhys( const phy_set_t *rxPhys ) { + tr_info("Set preferred PHYs - " + "txPhys=%s, " + "rxPhys=%s, ", + to_string(*txPhys), + to_string(*rxPhys)); + phy_set_t tx_phys(txPhys ? txPhys->value() : 0); phy_set_t rx_phys(rxPhys ? rxPhys->value() : 0); return _pal_gap.set_preferred_phys(tx_phys, rx_phys); @@ -791,6 +886,15 @@ ble_error_t Gap::setPhy( ble::coded_symbol_per_bit_t codedSymbol ) { + tr_info("Set PHY for connection %d - " + "txPhys=%s, " + "rxPhys=%s, " + "codedSymbol=%s", + connection, + to_string(*txPhys), + to_string(*rxPhys), + to_string(codedSymbol)); + phy_set_t tx_phys(txPhys ? txPhys->value() : 0); phy_set_t rx_phys(rxPhys ? rxPhys->value() : 0); return _pal_gap.set_phy(connection, tx_phys, rx_phys, codedSymbol); @@ -852,6 +956,11 @@ ble_error_t Gap::disconnect( local_disconnection_reason_t reason ) { + tr_info("Connection %d: disconnect - " + "reason=%s", + connectionHandle, + to_string(reason)); + return _pal_gap.disconnect(connectionHandle, reason); } #endif // BLE_FEATURE_CONNECTABLE @@ -865,10 +974,12 @@ uint8_t Gap::getMaxWhitelistSize(void) const ble_error_t Gap::getWhitelist(whitelist_t &whitelist) const { if (initialize_whitelist() == false) { + tr_error("Cannot get whitelist: failed to initialize"); return BLE_ERROR_INVALID_STATE; } if (whitelist.capacity < _whitelist.capacity) { + tr_error("Cannot get whitelist: capacity less than %d", _whitelist.capacity); return BLE_ERROR_INVALID_PARAM; } @@ -882,15 +993,19 @@ ble_error_t Gap::getWhitelist(whitelist_t &whitelist) const ble_error_t Gap::setWhitelist(const whitelist_t &whitelist) { + tr_info("Set whitelist"); if (is_whitelist_valid(whitelist) == false) { + tr_error("not a valid whitelist"); return BLE_ERROR_INVALID_PARAM; } if (initialize_whitelist() == false) { + tr_error("could not initialize whitelist"); return BLE_ERROR_INVALID_STATE; } if (whitelist.capacity > _whitelist.capacity) { + tr_error("capacity of whitelist greater than %d", _whitelist.capacity); return BLE_ERROR_INVALID_PARAM; } @@ -976,12 +1091,18 @@ ble_error_t Gap::setWhitelist(const whitelist_t &whitelist) #if BLE_FEATURE_PRIVACY ble_error_t Gap::enablePrivacy(bool enable) { + tr_info("Enable privacy -" + "enable=%s", + to_string(enable)); + if (enable == _privacy_enabled) { + tr_error("privacy already enabled"); // No change return BLE_ERROR_NONE; } if (is_radio_active()) { + tr_error("radio active"); return BLE_ERROR_INVALID_STATE; } @@ -1022,6 +1143,12 @@ ble_error_t Gap::setPeripheralPrivacyConfiguration( const peripheral_privacy_configuration_t *configuration ) { + tr_info("Set peripheral privacy configuration - " + "use_non_resolvable_random_address=%s, " + "resolution_strategy=%s", + to_string(configuration->use_non_resolvable_random_address), + to_string(configuration->resolution_strategy)); + _peripheral_privacy_configuration = *configuration; #if !BLE_GAP_HOST_BASED_PRIVATE_ADDRESS_RESOLUTION @@ -1055,6 +1182,8 @@ ble_error_t Gap::setCentralPrivacyConfiguration( #if !BLE_GAP_HOST_BASED_PRIVATE_ADDRESS_RESOLUTION if (_private_address_controller.is_controller_privacy_supported()) { update_ll_address_resolution_setting(); + } else { + tr_error("Failed to set central privacy configuration: controller privacy not supported"); } #endif // !BLE_GAP_HOST_BASED_PRIVATE_ADDRESS_RESOLUTION @@ -1148,17 +1277,21 @@ ble_error_t Gap::reset() void Gap::onShutdown(const GapShutdownCallback_t &callback) { + tr_info("GAP instance shutting down..."); shutdownCallChain.add(callback); } Gap::GapShutdownCallbackChain_t &Gap::onShutdown() { + tr_info("GAP instance shutting down..."); return shutdownCallChain; } #if BLE_ROLE_OBSERVER void Gap::on_scan_started(bool success) { + tr_info("Scan %s", success ? "successfully started" : "failed to start"); + MBED_ASSERT(_scan_state == ScanState::pending_scan); if (success) { @@ -1174,6 +1307,8 @@ void Gap::on_scan_started(bool success) void Gap::on_scan_stopped(bool success) { + tr_info("Scan %s", success ? "successfully stopped" : "failed to stop"); + if (!success) { return; } @@ -1190,6 +1325,7 @@ void Gap::on_scan_stopped(bool success) if (wait_for_advertising_stop) { /* return early if we're waiting for advertising to stop and do not restart scan even if requested */ + tr_error("advertising must be stopped before address can be refreshed"); return; } @@ -1216,6 +1352,8 @@ void Gap::on_scan_stopped(bool success) #if BLE_GAP_HOST_BASED_PRIVATE_ADDRESS_RESOLUTION void Gap::connecting_to_host_resolved_address_failed(bool inform_user) { + tr_info("Connecting to host resolved address failed%s", inform_user ? ", informing user" : ""); + if (inform_user && _event_handler) { _event_handler->onConnectionComplete( ConnectionCompleteEvent( @@ -1243,7 +1381,10 @@ void Gap::connecting_to_host_resolved_address_failed(bool inform_user) #if BLE_ROLE_OBSERVER void Gap::on_scan_timeout() { + tr_info("Scan timed out"); + if (_scan_state == ScanState::idle) { + tr_warning("event not passed to handler, scan state idle"); return; } @@ -1259,7 +1400,10 @@ void Gap::on_scan_timeout() #if BLE_ROLE_OBSERVER void Gap::process_legacy_scan_timeout() { + tr_info("Process legacy scan timed out"); + if (_scan_state == ScanState::idle) { + tr_warning("event not passed to handler, scan state idle"); return; } @@ -1274,11 +1418,15 @@ void Gap::process_legacy_scan_timeout() #if BLE_ROLE_BROADCASTER void Gap::on_advertising_timeout() { + tr_info("Advertising timed out"); + _event_queue.post(mbed::callback(this, &Gap::process_advertising_timeout)); } void Gap::process_advertising_timeout() { + tr_info("Process advertising timed out"); + if (!_active_sets.get(LEGACY_ADVERTISING_HANDLE)) { return; } @@ -1289,6 +1437,8 @@ void Gap::process_advertising_timeout() void Gap::on_gap_event_received(const GapEvent &e) { + tr_debug("GAP event of type %s received", to_string(e.type)); + switch (e.type.value()) { #if BLE_ROLE_OBSERVER case GapEventType::ADVERTISING_REPORT: @@ -1324,9 +1474,24 @@ void Gap::on_gap_event_received(const GapEvent &e) #if BLE_ROLE_OBSERVER void Gap::on_advertising_report(const GapAdvertisingReportEvent &e) { + tr_info("GAP advertising report received"); + for (size_t i = 0; i < e.size(); ++i) { GapAdvertisingReportEvent::advertising_t advertising = e[i]; + tr_debug("Advertising %d - " + "type=%s, " + "address_type=%s, " + "address=%s, " + "data=%s, " + "rssi=%d", + i, /* Advertising number */ + to_string(advertising.type), + to_string(advertising.address_type), + to_string(advertising.address), + mbed_trace_array(advertising.data.data(), advertising.data.size()), + advertising.rssi); + // note 1-to-1 conversion between connection_peer_address_type_t and // peer_address_type_t peer_address_type_t peer_address_type = @@ -1384,6 +1549,26 @@ void Gap::on_advertising_report(const GapAdvertisingReportEvent &e) #if BLE_FEATURE_CONNECTABLE void Gap::on_connection_complete(const GapConnectionCompleteEvent &e) { + tr_info("Connection %d %s - " + "role=%s, " + "peer_address_type=%s " + "peer_address=%s, " + "connection_interval=%d, " + "connection_latency=%d, " + "supervision_timeout=%d, " + "local_resolvable_private_address=%s, " + "peer_resolvable_private_address=%s", + e.connection_handle, + e.status == 0 ? "successfully completed" : "failed to complete", + e.status == 0 ? to_string(e.role) : "n/a", + to_string(e.peer_address_type), + to_string(e.peer_address), + e.connection_interval, + e.connection_latency, + e.supervision_timeout, + to_string(e.local_resolvable_private_address), + to_string(e.peer_resolvable_private_address)); + if (e.role == connection_role_t::CENTRAL) { _initiating = false; } @@ -1444,6 +1629,15 @@ void Gap::on_connection_complete(const GapConnectionCompleteEvent &e) void Gap::on_disconnection_complete(const GapDisconnectionCompleteEvent &e) { + if (e.status == 0) { + tr_info("Disconnection %d successfully completed - " + "reason=%d", + e.connection_handle, + e.reason); + } else { + tr_info("Disconnection %d failed", e.connection_handle); + } + if (e.status == hci_error_code_t::SUCCESS) { // signal internal stack if (_connection_event_handler) { @@ -1469,6 +1663,17 @@ void Gap::on_disconnection_complete(const GapDisconnectionCompleteEvent &e) void Gap::on_connection_parameter_request(const GapRemoteConnectionParameterRequestEvent &e) { + tr_info("Connection %d parameter request - " + "min_connection_interval=%d, " + "max_connection_interval=%d, " + "connection_latency=%d, " + "supervision_timeout=%d", + e.connection_handle, + e.min_connection_interval, + e.max_connection_interval, + e.connection_latency, + e.supervision_timeout); + if (_user_manage_connection_parameter_requests) { if (_event_handler) { _event_handler->onUpdateConnectionParametersRequest( @@ -1498,6 +1703,16 @@ void Gap::on_connection_parameter_request(const GapRemoteConnectionParameterRequ void Gap::on_connection_update(const GapConnectionUpdateEvent &e) { + tr_info("Connection %d update %s - " + "connection_interval=%d, " + "connection_latency=%d," + "supervision_timeout=%d, ", + e.connection_handle, + e.status == 0 ? "successfully completed" : "failed", + e.connection_interval, + e.connection_latency, + e.supervision_timeout); + if (!_event_handler) { return; } @@ -1561,18 +1776,23 @@ own_address_type_t Gap::get_own_address_type(AddressUseType_t address_use_type) #if BLE_FEATURE_WHITELIST bool Gap::initialize_whitelist() const { + tr_info("Initialize whitelist"); + if (_whitelist.addresses != nullptr) { + tr_error("whitelist already initialized"); return true; } uint8_t whitelist_capacity = _pal_gap.read_white_list_capacity(); if (whitelist_capacity == 0) { + tr_error("capacity of whitelist is zero"); return false; } _whitelist.addresses = new(std::nothrow) whitelist_t::entry_t[whitelist_capacity]; if (_whitelist.addresses == nullptr) { + tr_error("failed to dynamically allocate memory for a whitelist of %d addresses", whitelist_capacity); return false; } @@ -1654,7 +1874,9 @@ ble_error_t Gap::createAdvertisingSet( const AdvertisingParameters ¶meters ) { + tr_info("Create advertising set"); if (is_extended_advertising_available() == false) { + tr_error("extended advertising not available"); return BLE_ERROR_OPERATION_NOT_PERMITTED; } @@ -1676,6 +1898,7 @@ ble_error_t Gap::createAdvertisingSet( ); if (err) { + tr_error("could not set advertising parameters"); _existing_sets.clear(new_handle); } else { *handle = new_handle; @@ -1684,6 +1907,7 @@ ble_error_t Gap::createAdvertisingSet( } } + tr_info("Success: created advertising set %d", *handle); return BLE_ERROR_NO_MEM; } #endif @@ -1694,33 +1918,41 @@ ble_error_t Gap::createAdvertisingSet( #if BLE_FEATURE_EXTENDED_ADVERTISING ble_error_t Gap::destroyAdvertisingSet(advertising_handle_t handle) { + tr_info("Destroy advertising set %d", handle); if (is_extended_advertising_available() == false) { + tr_error("extended advertising not available"); return BLE_ERROR_OPERATION_NOT_PERMITTED; } if (handle == LEGACY_ADVERTISING_HANDLE) { + tr_error("handle cannot be equal to %d", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("handle cannot be greater than/equal to %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } if (!_existing_sets.get(handle)) { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } if (_pending_sets.get(handle) || _active_sets.get(handle)) { + tr_error("active advertising set"); return BLE_ERROR_OPERATION_NOT_PERMITTED; } #if BLE_FEATURE_PERIODIC_ADVERTISING if (_active_periodic_sets.get(handle)) { + tr_error("active periodic advertising set"); return BLE_ERROR_OPERATION_NOT_PERMITTED; } #endif // BLE_FEATURE_PERIODIC_ADVERTISING ble_error_t err = _pal_gap.remove_advertising_set(handle); if (err) { + tr_error("PAL could not remove advertising set"); return err; } @@ -1739,18 +1971,60 @@ ble_error_t Gap::setAdvertisingParameters( const AdvertisingParameters ¶ms ) { + tr_info("Advertising set %d: set advertising parameters - " + "_advType=%s, " + "_minInterval=%" PRIu32 "ms, " + "_maxInterval=%" PRIu32 "ms, " + "_peerAddressType=%s, " + "_ownAddressType=%s, " + "_policy=%s, " + "_primaryPhy=%s, " + "_secondaryPhy=%s, " + "_peerAddress=%s, " + "_txPower=%d, " + "_maxSkip=%u, " + "_channel37=%s, " + "_channel38=%s, " + "_channel39=%s, " + "_anonymous=%s, " + "_notifyOnScan=%s, " + "_legacyPDU=%s, " + "_includeHeaderTxPower=%s", + handle, + to_string(params.getType()), + params.getMinPrimaryInterval().valueInMs(), + params.getMaxPrimaryInterval().valueInMs(), + to_string(params.getPeerAddressType()), + to_string(params.getOwnAddressType()), + to_string(params.getFilter()), + to_string(params.getPrimaryPhy()), + to_string(params.getSecondaryPhy()), + to_string(params.getPeerAddress()), + params.getTxPower(), + params.getSecondaryMaxSkip(), + to_string(params.getChannel37()), + to_string(params.getChannel38()), + to_string(params.getChannel39()), + to_string(params.getAnonymousAdvertising()), + to_string(params.getScanRequestNotification()), + to_string(params.getUseLegacyPDU()), + to_string(params.getTxPowerInHeader())); + if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("handle cannot be greater than/equal to %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } - // It is not permited to reconfigure an advertising set while advertising + // It is not permitted to reconfigure an advertising set while advertising if (_pending_sets.get(handle) || _active_sets.get(handle)) { + tr_error("active advertising set"); return BLE_ERROR_OPERATION_NOT_PERMITTED; } #if BLE_FEATURE_PRIVACY // If privacy is enabled, alter the own address type used during advertising if (_privacy_enabled && params.getOwnAddressType() != own_address_type_t::RANDOM) { + tr_error("privacy enabled, cannot use random address"); return BLE_ERROR_INVALID_PARAM; } #endif @@ -1760,6 +2034,7 @@ ble_error_t Gap::setAdvertisingParameters( if (handle == LEGACY_ADVERTISING_HANDLE) { return prepare_legacy_advertising_set(params); } else { + tr_error("legacy advertising, handle must be equal to %d", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } } else if (is_extended_advertising_available()) { @@ -1768,6 +2043,7 @@ ble_error_t Gap::setAdvertisingParameters( #endif // BLE_FEATURE_EXTENDED_ADVERTISING { if (handle != LEGACY_ADVERTISING_HANDLE) { + tr_error("legacy advertising, handle must be equal to %d", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } @@ -1790,6 +2066,8 @@ ble_error_t Gap::setAdvertisingParameters( if (!err) { update_advertising_set_connectable_attribute(handle, params); + } else { + tr_error("PAL could not set advertising parameters"); } return err; } @@ -1803,12 +2081,52 @@ ble_error_t Gap::setExtendedAdvertisingParameters( const AdvertisingParameters ¶ms ) { + tr_info("Advertising set %d: set extended advertising parameters - " + "_advType=%s, " + "_minInterval=%" PRIu32 "ms, " + "_maxInterval=%" PRIu32 "ms, " + "_peerAddressType=%s, " + "_ownAddressType=%s, " + "_policy=%s, " + "_primaryPhy=%s, " + "_secondaryPhy=%s, " + "_peerAddress=%s, " + "_txPower=%d, " + "_maxSkip=%u, " + "_channel37=%s, " + "_channel38=%s, " + "_channel39=%s, " + "_anonymous=%s, " + "_notifyOnScan=%s, " + "_legacyPDU=%s, " + "_includeHeaderTxPower=%s", + handle, + to_string(params.getType()), + params.getMinPrimaryInterval().valueInMs(), + params.getMaxPrimaryInterval().valueInMs(), + to_string(params.getPeerAddressType()), + to_string(params.getOwnAddressType()), + to_string(params.getFilter()), + to_string(params.getPrimaryPhy()), + to_string(params.getSecondaryPhy()), + to_string(params.getPeerAddress()), + params.getTxPower(), + params.getSecondaryMaxSkip(), + to_string(params.getChannel37()), + to_string(params.getChannel38()), + to_string(params.getChannel39()), + to_string(params.getAnonymousAdvertising()), + to_string(params.getScanRequestNotification()), + to_string(params.getUseLegacyPDU()), + to_string(params.getTxPowerInHeader())); + /* check for illegal parameter combination */ if ((params.getType() == advertising_type_t::CONNECTABLE_UNDIRECTED || params.getType() == advertising_type_t::CONNECTABLE_DIRECTED) && params.getUseLegacyPDU() == false ) { /* these types can only be used with legacy PDUs */ + tr_error("directed and undirected connections can only be used with legacy PDUs"); return BLE_ERROR_INVALID_PARAM; } @@ -1843,6 +2161,8 @@ ble_error_t Gap::setExtendedAdvertisingParameters( if (!err) { update_advertising_set_connectable_attribute(handle, params); + } else { + tr_error("PAL could not set extended advertising parameters"); } return err; @@ -1889,6 +2209,15 @@ ble_error_t Gap::setAdvertisingData( bool scan_response ) { + tr_info("Advertising set %d: set advertising data - " + "payload=%s, " + "minimiseFragmentation=%s, " + "scan_response=%s", + handle, + mbed_trace_array(payload.data(), payload.size()), + to_string(minimiseFragmentation), + to_string(scan_response)); + // type declarations typedef advertising_fragment_description_t op_t; typedef ble_error_t (PalGap::*legacy_set_data_fn_t)( @@ -1905,6 +2234,7 @@ ble_error_t Gap::setAdvertisingData( #if BLE_FEATURE_EXTENDED_ADVERTISING if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } @@ -1912,6 +2242,7 @@ ble_error_t Gap::setAdvertisingData( if (handle == LEGACY_ADVERTISING_HANDLE) { prepare_legacy_advertising_set(AdvertisingParameters{}); } else { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } } @@ -1920,10 +2251,12 @@ ble_error_t Gap::setAdvertisingData( if (is_extended_advertising_available() == false) { #endif // BLE_FEATURE_EXTENDED_ADVERTISING if (handle != LEGACY_ADVERTISING_HANDLE) { + tr_error("handle must be equal to %d for legacy advertising", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } if (payload.size() > LEGACY_ADVERTISING_MAX_SIZE) { + tr_error("legacy advertising payload size cannot be greater than %d", LEGACY_ADVERTISING_MAX_SIZE); return BLE_ERROR_INVALID_PARAM; } @@ -1941,21 +2274,19 @@ ble_error_t Gap::setAdvertisingData( } if (payload.size() > getMaxAdvertisingDataLength()) { - MBED_WARNING(MBED_ERROR_INVALID_SIZE, "Payload size exceeds getMaxAdvertisingDataLength()."); + tr_error("payload size cannot be greater than %u", getMaxAdvertisingDataLength()); return BLE_ERROR_INVALID_PARAM; } if ((_pending_sets.get(handle) || _active_sets.get(handle)) && payload.size() > this->getMaxActiveSetAdvertisingDataLength()) { - MBED_WARNING(MBED_ERROR_INVALID_SIZE, "Payload size for active sets needs to fit in a single operation" - " - not greater than getMaxActiveSetAdvertisingDataLength()."); + tr_error ("payload size for active sets cannot be greater than %u", getMaxActiveSetAdvertisingDataLength()); return BLE_ERROR_INVALID_PARAM; } if (!scan_response) { if (payload.size() > this->getMaxConnectableAdvertisingDataLength()) { if ((_pending_sets.get(handle) || _active_sets.get(handle)) && _set_is_connectable.get(handle)) { - MBED_WARNING(MBED_ERROR_INVALID_SIZE, "Payload size for connectable advertising" - " exceeds getMaxAdvertisingDataLength()."); + tr_error("payload size for connectable advertising cannot be greater %u", getMaxAdvertisingDataLength()); return BLE_ERROR_INVALID_PARAM; } else { _connectable_payload_size_exceeded.set(handle); @@ -2014,31 +2345,42 @@ ble_error_t Gap::startAdvertising( uint8_t maxEvents ) { + tr_info("Advertising set %d: start advertising - " + "maxDuration=%" PRIu32 "ms, " + "maxEvents=%u", + handle, + maxDuration.valueInMs(), + maxEvents); + ble_error_t error = BLE_ERROR_NONE; // the stack is busy because it is starting, stopping or refreshing internally // the address. if (_pending_sets.get(handle) || _address_refresh_sets.get(handle)) { + tr_error("stack busy"); return BLE_STACK_BUSY; } #if BLE_FEATURE_EXTENDED_ADVERTISING if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("handle cannot be greater than/equal to %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } if (!_existing_sets.get(handle)) { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } if (_connectable_payload_size_exceeded.get(handle) && _set_is_connectable.get(handle)) { - MBED_WARNING(MBED_ERROR_INVALID_SIZE, "Payload size exceeds size allowed for connectable advertising."); + tr_error("payload size exceeds size allowed for connectable advertising"); return BLE_ERROR_INVALID_STATE; } #endif // BLE_FEATURE_EXTENDED_ADVERTISING const address_t* random_address = get_random_address(controller_operation_t::advertising, handle); if (!random_address) { + tr_error("could not get random address"); return BLE_ERROR_INVALID_STATE; } @@ -2074,16 +2416,20 @@ ble_error_t Gap::startAdvertising( #endif // BLE_FEATURE_EXTENDED_ADVERTISING { if (handle != LEGACY_ADVERTISING_HANDLE) { + tr_error("legacy advertising, handle must be equal to %d", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } // Address can be updated if the device is not scanning or advertising if ((_scan_state == ScanState::idle) && !_active_sets.get(LEGACY_ADVERTISING_HANDLE)) { _pal_gap.set_random_address(*random_address); + } else { + tr_error("could not update address, device scanning/advertising"); } error = _pal_gap.advertising_enable(true); if (error) { + tr_error("PAL could not enable advertising"); return error; } @@ -2108,19 +2454,23 @@ ble_error_t Gap::startAdvertising( #if BLE_ROLE_BROADCASTER ble_error_t Gap::stopAdvertising(advertising_handle_t handle) { + tr_info("Advertising set %d: stop advertising", handle); ble_error_t status; #if BLE_FEATURE_EXTENDED_ADVERTISING if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("handle cannot be greater than/equal to %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } if (!_existing_sets.get(handle)) { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } #endif // BLE_FEATURE_EXTENDED_ADVERTISING if (_pending_sets.get(handle)) { + tr_error("set pending"); return BLE_STACK_BUSY; } @@ -2145,6 +2495,7 @@ ble_error_t Gap::stopAdvertising(advertising_handle_t handle) #endif // BLE_FEATURE_EXTENDED_ADVERTISING { if (handle != LEGACY_ADVERTISING_HANDLE) { + tr_error("legacy advertising, handle must be equal to %d", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } @@ -2168,6 +2519,7 @@ ble_error_t Gap::stopAdvertising(advertising_handle_t handle) bool Gap::isAdvertisingActive(advertising_handle_t handle) { if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("Cannot determine if periodic advertising is active: handle greater than/equal to %d", getMaxAdvertisingSetNumber()); return false; } @@ -2185,19 +2537,32 @@ ble_error_t Gap::setPeriodicAdvertisingParameters( bool advertiseTxPower ) { + tr_info("Advertising et %d: set periodic advertising parameters- " + "periodicAdvertisingIntervalMin=%" PRIu32 "ms, " + "periodicAdvertisingIntervalMax=%" PRIu32 "ms, " + "advertiseTxPower=%s", + handle, + periodicAdvertisingIntervalMin.valueInMs(), + periodicAdvertisingIntervalMax.valueInMs(), + to_string(advertiseTxPower)); + if (periodicAdvertisingIntervalMin.value() > periodicAdvertisingIntervalMax.value()) { + tr_error("min. adv. interval cannot be greater than max. adv. interval"); return BLE_ERROR_INVALID_PARAM; } if (handle == LEGACY_ADVERTISING_HANDLE) { + tr_error("handle cannot be equal to %d", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("handle cannot be greater than/equal to %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } if (!_existing_sets.get(handle)) { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } @@ -2219,19 +2584,27 @@ ble_error_t Gap::setPeriodicAdvertisingPayload( Span payload ) { + tr_info("Advertising set %d: set periodic advertising payload", handle); +#if TRACE_WRITE_VALUES + tr_debug("payload=%s", mbed_trace_array(payload, payload.size())); +#endif if (handle == LEGACY_ADVERTISING_HANDLE) { + tr_error("handle cannot be equal to %d", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("handle cannot be greater than/equal %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } if (!_existing_sets.get(handle)) { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } if (payload.size() > getMaxAdvertisingDataLength()) { + tr_error("payload size cannot be greater than %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } @@ -2284,23 +2657,29 @@ ble_error_t Gap::setPeriodicAdvertisingPayload( #if BLE_FEATURE_PERIODIC_ADVERTISING ble_error_t Gap::startPeriodicAdvertising(advertising_handle_t handle) { + tr_info("Advertising set %d: start periodic advertising", handle); if (handle == LEGACY_ADVERTISING_HANDLE) { + tr_error("handle cannot be equal to %d", LEGACY_ADVERTISING_HANDLE); return BLE_ERROR_INVALID_PARAM; } if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("handle cannot be greater than/equal to %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } if (!_existing_sets.get(handle)) { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } if (_active_sets.get(handle) == false) { + tr_error("inactive advertising set"); return BLE_ERROR_INVALID_STATE; } if (_active_periodic_sets.get(handle) == true) { + tr_error("active periodic advertising set"); return BLE_ERROR_INVALID_STATE; } @@ -2320,19 +2699,24 @@ ble_error_t Gap::startPeriodicAdvertising(advertising_handle_t handle) #if BLE_FEATURE_PERIODIC_ADVERTISING ble_error_t Gap::stopPeriodicAdvertising(advertising_handle_t handle) { + tr_info("Advertising set %d: stop periodic advertising", handle); if (handle == LEGACY_ADVERTISING_HANDLE) { + tr_error("handle cannot be equal to %d", handle); return BLE_ERROR_INVALID_PARAM; } if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("handle cannot be greater than/equal to %d", getMaxAdvertisingSetNumber()); return BLE_ERROR_INVALID_PARAM; } if (!_existing_sets.get(handle)) { + tr_error("non-existent advertising set"); return BLE_ERROR_INVALID_PARAM; } if (_active_periodic_sets.get(handle) == false) { + tr_error("inactive advertising set"); return BLE_ERROR_INVALID_STATE; } @@ -2353,6 +2737,7 @@ ble_error_t Gap::stopPeriodicAdvertising(advertising_handle_t handle) bool Gap::isPeriodicAdvertisingActive(advertising_handle_t handle) { if (handle >= getMaxAdvertisingSetNumber()) { + tr_error("Can't determine if periodic advertising is active: handle greater than/equal to %d", getMaxAdvertisingSetNumber()); return false; } @@ -2379,6 +2764,49 @@ void Gap::on_extended_advertising_report( const uint8_t *data ) { + tr_debug("Extended advertising report - " + "event_type=[" + "connectable=%s, " + "scannable_advertising=%s, " + "direct_advertising=%s, " + "scan_response=%s, " + "legacy_advertising=%s, " + "complete=%s, " + "more_data_to_come=%s, " + "truncated=%s], " + "address_type=%s, " + "address=%s, " + "primary_phy=%s, " + "secondary_phy=%s, " + "advertising_sid=%d, " + "tx_power=%d, " + "rssi=%d, " + "periodic_advertising_interval=%d, " + "direct_address_type=%s, " + "direct_address=%s," + "data_length=%d, " + "data=%s", + to_string(event_type.connectable()), + to_string(event_type.scannable_advertising()), + to_string(event_type.directed_advertising()), + to_string(event_type.scan_response()), + to_string(event_type.legacy_advertising()), + to_string(event_type.complete()), + to_string(event_type.more_data_to_come()), + to_string(event_type.truncated()), + to_string(*address_type), + to_string(address), + to_string(primary_phy), + to_string(*secondary_phy), + advertising_sid, + tx_power, + rssi, + periodic_advertising_interval, + to_string(direct_address_type), + to_string(direct_address), + data_length, + mbed_trace_array(data, data_length)); + if (!_event_handler) { return; } @@ -2510,6 +2938,9 @@ void Gap::signal_connection_complete( _event_handler->onConnectionComplete( event ); + tr_info("Connection %d: disconnecting - reason=%s", + event.getConnectionHandle(), + to_string(local_disconnection_reason_t::LOW_RESOURCES)); _pal_gap.disconnect( event.getConnectionHandle(), local_disconnection_reason_t::LOW_RESOURCES @@ -2553,6 +2984,9 @@ bool Gap::apply_peripheral_privacy_connection_policy( if (_private_address_controller.read_resolving_list_size() == 0) { return true; } + tr_info("Connection %d: disconnecting - reason=%s", + event.getConnectionHandle(), + to_string(local_disconnection_reason_t::AUTHENTICATION_FAILURE)); _pal_gap.disconnect( connection_handle, local_disconnection_reason_t::AUTHENTICATION_FAILURE @@ -2767,6 +3201,23 @@ void Gap::on_periodic_advertising_sync_established( clock_accuracy_t clock_accuracy ) { + tr_info("Sync %d: periodic advertising sync established - " + "error=%s, " + "advertising_sid=%d, " + "advertiser_address_typ=%s, " + "advertiser_address=%s, " + "advertiser_phy=%s, " + "periodic_advertising_interval=%d, " + "clock_accuracy=%d ppm", + sync_handle, + to_string(error), + advertising_sid, + to_string(advertiser_address_type), + to_string(advertiser_address), + to_string(advertiser_phy), + periodic_advertising_interval, + clock_accuracy.get_ppm()); + if (!_event_handler) { return; } @@ -2795,6 +3246,19 @@ void Gap::on_periodic_advertising_report( const uint8_t *data ) { + tr_debug("Sync %d: periodic advertising report - " + "tx_power=%d, " + "rssi=%d," + "data_status=%s, " + "data_length=%d," + "data=%s", + sync_handle, + tx_power, + rssi, + to_string(data_status), + data_length, + mbed_trace_array(data, data_length)); + if (!_event_handler) { return; } @@ -2813,6 +3277,8 @@ void Gap::on_periodic_advertising_report( void Gap::on_periodic_advertising_sync_loss(sync_handle_t sync_handle) { + tr_info("Sync %d: periodic advertising sync loss", sync_handle); + if (!_event_handler) { return; } @@ -2827,6 +3293,8 @@ void Gap::on_periodic_advertising_sync_loss(sync_handle_t sync_handle) #if BLE_ROLE_BROADCASTER void Gap::on_legacy_advertising_started() { + tr_info("Legacy advertising started"); + _active_sets.set(LEGACY_ADVERTISING_HANDLE); _pending_sets.clear(LEGACY_ADVERTISING_HANDLE); @@ -2841,6 +3309,8 @@ void Gap::on_legacy_advertising_started() void Gap::on_legacy_advertising_stopped() { + tr_info("Legacy advertising stopped"); + _active_sets.clear(LEGACY_ADVERTISING_HANDLE); _pending_sets.clear(LEGACY_ADVERTISING_HANDLE); @@ -2863,6 +3333,8 @@ void Gap::on_legacy_advertising_stopped() #if BLE_FEATURE_EXTENDED_ADVERTISING void Gap::on_advertising_set_started(const mbed::Span& handles) { + tr_info("Advertising set started - handles=%s", mbed_trace_array(handles.data(), handles.size())); + for (const auto &handle : handles) { _active_sets.set(handle); _pending_sets.clear(handle); @@ -2883,12 +3355,21 @@ void Gap::on_advertising_set_terminated( uint8_t number_of_completed_extended_advertising_events ) { + tr_info("Advertising set %d on connection %d terminated - " + "status=%s, " + "number_of_completed_extended_advertising_events=%d ", + advertising_handle, + connection_handle, + to_string(status), + number_of_completed_extended_advertising_events); + _active_sets.clear(advertising_handle); _pending_sets.clear(advertising_handle); // If this is part of the address refresh start advertising again. if (_address_refresh_sets.get(advertising_handle) && !connection_handle) { _address_refresh_sets.clear(advertising_handle); + tr_info("Part of the address refresh, restarting advertising"); startAdvertising(advertising_handle); _adv_started_from_refresh.set(advertising_handle); return; @@ -2914,6 +3395,13 @@ void Gap::on_scan_request_received( const ble::address_t &address ) { + tr_info("Advertising set %d: scan request received - " + "scanner_address_type=%s, " + "address=%s", + advertising_handle, + to_string(scanner_address_type), + to_string(address)); + if (!_event_handler) { return; } @@ -2938,6 +3426,17 @@ void Gap::on_connection_update_complete( uint16_t supervision_timeout ) { + tr_info("Update complete for connection %d - " + "status=%s, " + "connection_interval=%d, " + "connection_latency=%d, " + "supervision_timeout=%d", + connection_handle, + to_string(status), + connection_interval, + connection_latency, + supervision_timeout); + if (!_event_handler) { return; } @@ -2961,6 +3460,17 @@ void Gap::on_remote_connection_parameter( uint16_t supervision_timeout ) { + tr_info("Connection %d: remote connection parameter request - " + "connection_interval_min=%d, " + "connection_interval_max=%d, " + "connection_latency=%d, " + "supervision_timeout=%d", + connection_handle, + connection_interval_min, + connection_interval_max, + connection_latency, + supervision_timeout); + if (_user_manage_connection_parameter_requests) { if (_event_handler) { _event_handler->onUpdateConnectionParametersRequest( @@ -2989,7 +3499,34 @@ void Gap::on_remote_connection_parameter( #if BLE_ROLE_OBSERVER ble_error_t Gap::setScanParameters(const ScanParameters ¶ms) { + if (params.get1mPhyConfiguration().isActiveScanningSet()) { + tr_info("Set scan parameters - " + "own_address_type=%s, " + "scanning_filter_policy=%s, " + "phys=%d, " + "phy_1m_configuration:[interval=%" PRIu32 "ms,window=%" PRIu32 "ms,active_scanning=%s]", + to_string(params.getOwnAddressType()), + to_string(params.getFilter()), + params.getPhys().value(), + params.get1mPhyConfiguration().getInterval().valueInMs(), + params.get1mPhyConfiguration().getWindow().valueInMs(), + to_string(params.get1mPhyConfiguration().isActiveScanningSet())); + } else { + tr_info("Set scan parameters - " + "own_address_type=%s, " + "scanning_filter_policy=%s, " + "phys=%d, " + "phy_coded_configuration:[interval=%" PRIu32 "ms,window=%" PRIu32 "ms,active_scanning=%s]", + to_string(params.getOwnAddressType()), + to_string(params.getFilter()), + params.getPhys().value(), + params.getCodedPhyConfiguration().getInterval().valueInMs(), + params.getCodedPhyConfiguration().getWindow().valueInMs(), + to_string(params.getCodedPhyConfiguration().isActiveScanningSet())); + } + if (_privacy_enabled && params.getOwnAddressType() != own_address_type_t::RANDOM) { + tr_error("privacy enabled, cannot use random address"); return BLE_ERROR_INVALID_PARAM; } @@ -3022,6 +3559,7 @@ ble_error_t Gap::setScanParameters(const ScanParameters ¶ms) #endif { if (params.getPhys().get_coded()) { + tr_error("cannot use coded PHY with legacy configuration"); return BLE_ERROR_INVALID_PARAM; } @@ -3047,7 +3585,16 @@ ble_error_t Gap::startScan( scan_period_t period ) { + tr_info("Start scan - " + "duration=%" PRIu32 "ms, " + "filtering=%s, " + "period=%" PRIu32 "ms", + duration.valueInMs(), + to_string(filtering), + period.valueInMs()); + if (_initiating) { + tr_error("busy trying to connect"); return BLE_STACK_BUSY; } @@ -3070,8 +3617,10 @@ ble_error_t Gap::startScan( ble_error_t Gap::initiate_scan() { + tr_info("Initiate scan"); const address_t *address = get_random_address(controller_operation_t::scanning); if (!address) { + tr_error("could not get random address"); return BLE_ERROR_INVALID_STATE; } @@ -3096,6 +3645,7 @@ ble_error_t Gap::initiate_scan() #endif // BLE_FEATURE_EXTENDED_ADVERTISING { if (_scan_requested_period.value() != 0) { + tr_error("scan request period cannot be equal to 0"); return BLE_ERROR_INVALID_PARAM; } @@ -3139,17 +3689,32 @@ ble_error_t Gap::createSync( sync_timeout_t timeout ) { + tr_info("Create sync - " + "peerAddressType=%s, " + "peerAddress=%s, " + "sid=%u, " + "maxPacketSkip=%hu, " + "timeout=%" PRIu32 "ms", + to_string(peerAddressType), + to_string(peerAddress), + sid, + maxPacketSkip.value(), + timeout.valueInMs()); + if (is_extended_advertising_available() == false) { + tr_error("extended advertising not available"); return BLE_ERROR_NOT_IMPLEMENTED; } if (peerAddressType != peer_address_type_t::PUBLIC && peerAddressType != peer_address_type_t::RANDOM ) { + tr_error("peer address type must be public/random"); return BLE_ERROR_INVALID_PARAM; } if (sid > 0x0F) { + tr_error("sid cannot be greater than 0x0F"); return BLE_ERROR_INVALID_PARAM; } @@ -3173,7 +3738,14 @@ ble_error_t Gap::createSync( sync_timeout_t timeout ) { + tr_info("Create sync - " + "maxPacketSkip=%hu, " + "timeout=%" PRIu32 "ms", + maxPacketSkip.value(), + timeout.valueInMs()); + if (is_extended_advertising_available() == false) { + tr_error("extended advertising not available"); return BLE_ERROR_NOT_IMPLEMENTED; } @@ -3195,6 +3767,7 @@ ble_error_t Gap::createSync( ble_error_t Gap::cancelCreateSync() { if (is_extended_advertising_available() == false) { + tr_error("Failed to cancel create sync: extended advertising not available"); return BLE_ERROR_NOT_IMPLEMENTED; } @@ -3208,7 +3781,10 @@ ble_error_t Gap::cancelCreateSync() #if BLE_FEATURE_PERIODIC_ADVERTISING ble_error_t Gap::terminateSync(periodic_sync_handle_t handle) { + tr_info("Teminate sync %d", handle); + if (is_extended_advertising_available() == false) { + tr_error("extended advertising not available"); return BLE_ERROR_NOT_IMPLEMENTED; } @@ -3226,16 +3802,27 @@ ble_error_t Gap::addDeviceToPeriodicAdvertiserList( advertising_sid_t sid ) { + tr_info("Add device to periodic advertising list - " + "peerAddressType=%s, " + "peerAddress=%s, " + "sid=%u", + to_string(peerAddressType), + to_string(peerAddress), + sid); + if (is_extended_advertising_available() == false) { + tr_error("extended advertising not available"); return BLE_ERROR_NOT_IMPLEMENTED; } if ((peerAddressType != peer_address_type_t::PUBLIC) && (peerAddressType != peer_address_type_t::RANDOM)) { + tr_error("peer address type must be public/random"); return BLE_ERROR_INVALID_PARAM; } if (sid > 0x0F) { + tr_error("sid cannot be greater than 0x0F"); return BLE_ERROR_INVALID_PARAM; } @@ -3257,16 +3844,27 @@ ble_error_t Gap::removeDeviceFromPeriodicAdvertiserList( advertising_sid_t sid ) { + tr_info("Remove device from periodic advertising list - " + "peerAddressType=%s, " + "peerAddress=%s, " + "sid=%u", + to_string(peerAddressType), + to_string(peerAddress), + sid); + if (is_extended_advertising_available() == false) { + tr_error("extended advertising not available"); return BLE_ERROR_NOT_IMPLEMENTED; } if ((peerAddressType != peer_address_type_t::PUBLIC) && (peerAddressType != peer_address_type_t::RANDOM)) { + tr_error("peer address must be public/random"); return BLE_ERROR_INVALID_PARAM; } if (sid > 0x0F) { + tr_error("set ID cannot be greater than 0x0F"); return BLE_ERROR_INVALID_PARAM; } @@ -3285,6 +3883,7 @@ ble_error_t Gap::removeDeviceFromPeriodicAdvertiserList( ble_error_t Gap::clearPeriodicAdvertiserList() { if (is_extended_advertising_available() == false) { + tr_error("Failed to clear periodic advertiser list: extended advertising not available"); return BLE_ERROR_NOT_IMPLEMENTED; } @@ -3299,6 +3898,7 @@ ble_error_t Gap::clearPeriodicAdvertiserList() uint8_t Gap::getMaxPeriodicAdvertiserListSize() { if (is_extended_advertising_available() == false) { + tr_error("Failed to get max. periodic advertiser list size: extended advertising not available"); return BLE_ERROR_NOT_IMPLEMENTED; } @@ -3343,6 +3943,9 @@ ble_error_t Gap::prepare_legacy_advertising_set(const AdvertisingParameters& par void Gap::setEventHandler(Gap::EventHandler *handler) { + if (handler == nullptr) { + tr_warning("Setting GAP event handler to a null pointer"); + } _event_handler = handler; } @@ -3359,7 +3962,10 @@ void Gap::on_non_resolvable_private_addresses_generated(const address_t &address void Gap::on_private_address_generated(bool connectable) { + tr_info("Private address generated - connectable=%s", to_string(connectable)); + if (!_privacy_enabled) { + tr_error("privacy enabled, not passing to event handler"); return; } @@ -3413,6 +4019,16 @@ void Gap::on_address_resolution_completed( const address_t &identity_address ) { + tr_info("Address resolution completed - " + "peer_resolvable_address=%s, " + "resolved=%s, " + "identity_address_type=%s, " + "identity_address=%s", + to_string(peer_resolvable_address), + to_string(resolved), + to_string(identity_address_type), + to_string(identity_address)); + if (!_event_handler || !_privacy_enabled) { return; }