diff --git a/subsys/bluetooth/controller/hci/hci.c b/subsys/bluetooth/controller/hci/hci.c index 683c4cadf919e..8bf7dc676602a 100644 --- a/subsys/bluetooth/controller/hci/hci.c +++ b/subsys/bluetooth/controller/hci/hci.c @@ -8951,13 +8951,13 @@ static void encode_control(struct node_rx_pdu *node_rx, #if defined(CONFIG_BT_CTLR_PROFILE_ISR) case NODE_RX_TYPE_PROFILE: - LOG_INF("l: %u, %u, %u; t: %u, %u, %u; cpu: %u (%u), %u (%u), %u (%u), %u (%u).", - pdu_data->profile.lcur, pdu_data->profile.lmin, pdu_data->profile.lmax, - pdu_data->profile.cur, pdu_data->profile.min, pdu_data->profile.max, - pdu_data->profile.radio, pdu_data->profile.radio_ticks, - pdu_data->profile.lll, pdu_data->profile.lll_ticks, - pdu_data->profile.ull_high, pdu_data->profile.ull_high_ticks, - pdu_data->profile.ull_low, pdu_data->profile.ull_low_ticks); + printk("l: %u, %u, %u; t: %u, %u, %u; cpu: %u (%u), %u (%u), %u (%u), %u (%u).\n", + pdu_data->profile.lcur, pdu_data->profile.lmin, pdu_data->profile.lmax, + pdu_data->profile.cur, pdu_data->profile.min, pdu_data->profile.max, + pdu_data->profile.radio, pdu_data->profile.radio_ticks, + pdu_data->profile.lll, pdu_data->profile.lll_ticks, + pdu_data->profile.ull_high, pdu_data->profile.ull_high_ticks, + pdu_data->profile.ull_low, pdu_data->profile.ull_low_ticks); return; #endif /* CONFIG_BT_CTLR_PROFILE_ISR */ diff --git a/subsys/bluetooth/controller/ll_sw/nordic/lll/lll.c b/subsys/bluetooth/controller/ll_sw/nordic/lll/lll.c index b44847c05850a..c8ff801c2c764 100644 --- a/subsys/bluetooth/controller/ll_sw/nordic/lll/lll.c +++ b/subsys/bluetooth/controller/ll_sw/nordic/lll/lll.c @@ -101,7 +101,9 @@ ISR_DIRECT_DECLARE(radio_nrf5_isr) { DEBUG_RADIO_ISR(1); - lll_prof_enter_radio(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_enter_radio(); + } isr_radio(); @@ -109,7 +111,9 @@ ISR_DIRECT_DECLARE(radio_nrf5_isr) ISR_DIRECT_PM(); #endif /* !CONFIG_BT_CTLR_ZLI */ - lll_prof_exit_radio(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_exit_radio(); + } DEBUG_RADIO_ISR(0); @@ -133,7 +137,9 @@ ISR_DIRECT_DECLARE(timer_nrf5_isr) { DEBUG_RADIO_ISR(1); - lll_prof_enter_radio(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_enter_radio(); + } isr_radio_tmr(); @@ -141,7 +147,9 @@ ISR_DIRECT_DECLARE(timer_nrf5_isr) ISR_DIRECT_PM(); #endif /* !CONFIG_BT_CTLR_ZLI */ - lll_prof_exit_radio(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_exit_radio(); + } DEBUG_RADIO_ISR(0); @@ -160,7 +168,9 @@ static void rtc0_nrf5_isr(const void *arg) { DEBUG_TICKER_ISR(1); - lll_prof_enter_ull_high(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_enter_ull_high(); + } /* On compare0 run ticker worker instance0 */ #if defined(CONFIG_BT_CTLR_NRF_GRTC) @@ -176,15 +186,21 @@ static void rtc0_nrf5_isr(const void *arg) mayfly_run(TICKER_USER_ID_ULL_HIGH); - lll_prof_exit_ull_high(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_exit_ull_high(); + } #if !defined(CONFIG_BT_CTLR_LOW_LAT) && \ (CONFIG_BT_CTLR_ULL_HIGH_PRIO == CONFIG_BT_CTLR_ULL_LOW_PRIO) - lll_prof_enter_ull_low(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_enter_ull_low(); + } mayfly_run(TICKER_USER_ID_ULL_LOW); - lll_prof_exit_ull_low(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_exit_ull_low(); + } #endif DEBUG_TICKER_ISR(0); @@ -194,11 +210,15 @@ static void swi_lll_nrf5_isr(const void *arg) { DEBUG_RADIO_ISR(1); - lll_prof_enter_lll(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_enter_lll(); + } mayfly_run(TICKER_USER_ID_LLL); - lll_prof_exit_lll(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_exit_lll(); + } DEBUG_RADIO_ISR(0); } @@ -209,11 +229,15 @@ static void swi_ull_low_nrf5_isr(const void *arg) { DEBUG_TICKER_JOB(1); - lll_prof_enter_ull_low(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_enter_ull_low(); + } mayfly_run(TICKER_USER_ID_ULL_LOW); - lll_prof_exit_ull_low(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_exit_ull_low(); + } DEBUG_TICKER_JOB(0); } diff --git a/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_adv.c b/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_adv.c index 5d1d897126197..8fd97a1afa019 100644 --- a/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_adv.c +++ b/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_adv.c @@ -1350,6 +1350,10 @@ static void isr_done(void *param) pdu = chan_prepare(lll); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_cputime_capture(); + } + #if defined(HAL_RADIO_GPIO_HAVE_PA_PIN) || defined(CONFIG_BT_CTLR_ADV_EXT) start_us = radio_tmr_start_now(1); @@ -1368,6 +1372,13 @@ static void isr_done(void *param) #endif /* !CONFIG_BT_CTLR_ADV_EXT */ #if defined(HAL_RADIO_GPIO_HAVE_PA_PIN) + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + /* PA/LNA enable is overwriting packet end used in ISR + * profiling, hence back it up for later use. + */ + lll_prof_radio_end_backup(); + } + radio_gpio_pa_setup(); radio_gpio_pa_lna_enable(start_us + radio_tx_ready_delay_get(0, 0) - @@ -1387,6 +1398,10 @@ static void isr_done(void *param) radio_filter_disable(); + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_cputime_capture(); + } + #if defined(CONFIG_BT_PERIPHERAL) if (!lll->is_hdcd) #endif /* CONFIG_BT_PERIPHERAL */ @@ -1433,6 +1448,19 @@ static void isr_done(void *param) lll_isr_cleanup(param); } +static void isr_tx_done(void *param) +{ + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_latency_capture(); + } + + isr_done(param); + + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + lll_prof_send(); + } +} + static void isr_abort(void *param) { /* Clear radio status and events */ @@ -1513,7 +1541,7 @@ static struct pdu_adv *chan_prepare(struct lll_adv *lll) radio_tmr_tifs_set(EVENT_IFS_US); radio_switch_complete_and_rx(0); } else { - radio_isr_set(isr_done, lll); + radio_isr_set(isr_tx_done, lll); if (IS_ENABLED(CONFIG_BT_CTLR_SW_SWITCH_SINGLE_TIMER) && IS_ENABLED(CONFIG_BT_CTLR_ADV_EXT)) { diff --git a/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_prof.c b/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_prof.c index 48323156f37e3..f2a0e27e8be53 100644 --- a/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_prof.c +++ b/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_prof.c @@ -12,6 +12,7 @@ #include "hal/ccm.h" #include "hal/radio.h" +#include "hal/ticker.h" #include "util/memq.h" @@ -23,12 +24,46 @@ #include "lll.h" +#include "hal/debug.h" + +/* Below profiling measurements using a sample with: + * 1 connectable legacy advertising or 1 peripheral ACL, + * plus + * 3 extended advertising sets, scanning on 2M PHY, scanning on Coded PHY, and + * 2 auxiliary scan set. + */ +#if defined(CONFIG_SOC_COMPATIBLE_NRF54LX) +#define LLL_PROF_RADIO_MAX_US 103 /* Max. Radio Rx/Tx ISR, O(1)*/ +#define LLL_PROF_LLL_MAX_US 105 /* Max. LLL prepare, O(1) */ +#define LLL_PROF_ULL_HIGH_MAX_US 260 /* Max. Radio + LLL + ULL High, O(1) */ +#define LLL_PROF_ULL_LOW_MAX_US 306 /* Max. ULL Low, O(n) n is ticker nodes */ +#else /* !CONFIG_SOC_COMPATIBLE_NRF54LX */ +#define LLL_PROF_RADIO_MAX_US 184 /* Max. Radio Rx/Tx ISR, O(1)*/ +#define LLL_PROF_LLL_MAX_US 245 /* Max. LLL prepare, O(1) */ +#define LLL_PROF_ULL_HIGH_MAX_US 458 /* Max. Radio + LLL + ULL High, O(1) */ +#define LLL_PROF_ULL_LOW_MAX_US 733 /* Max. ULL Low, O(n) n is ticker nodes */ +#endif /* !CONFIG_SOC_COMPATIBLE_NRF54LX */ + +#define LLL_PROF_ASSERT(_val, _max) \ + { \ + LL_ASSERT_MSG(((_val) <= (_max)), \ + "%s: %u (%u), %u (%u), %u (%u), %u (%u)\n", __func__, \ + HAL_TICKER_TICKS_TO_US(cputime_ticks_radio), \ + LLL_PROF_RADIO_MAX_US, \ + HAL_TICKER_TICKS_TO_US(cputime_ticks_lll), \ + LLL_PROF_LLL_MAX_US, \ + HAL_TICKER_TICKS_TO_US(cputime_ticks_ull_high), \ + LLL_PROF_ULL_HIGH_MAX_US, \ + HAL_TICKER_TICKS_TO_US(cputime_ticks_ull_low), \ + LLL_PROF_ULL_LOW_MAX_US); \ + } + static int send(struct node_rx_pdu *rx); static uint16_t latency_get(void); static inline void sample(uint32_t *timestamp); static inline void sample_ticks(uint32_t *timestamp_ticks); static inline void delta(uint32_t timestamp, uint16_t *cputime); -static inline void delta_ticks(uint32_t timestamp_ticks, uint8_t *cputime_ticks); +static inline void delta_ticks(uint32_t timestamp_ticks, uint16_t *cputime_ticks); static uint32_t timestamp_radio; static uint32_t timestamp_lll; @@ -50,10 +85,10 @@ static uint32_t timestamp_ticks_radio; static uint32_t timestamp_ticks_lll; static uint32_t timestamp_ticks_ull_high; static uint32_t timestamp_ticks_ull_low; -static uint8_t cputime_ticks_radio; -static uint8_t cputime_ticks_lll; -static uint8_t cputime_ticks_ull_high; -static uint8_t cputime_ticks_ull_low; +static uint16_t cputime_ticks_radio; +static uint16_t cputime_ticks_lll; +static uint16_t cputime_ticks_ull_high; +static uint16_t cputime_ticks_ull_low; void lll_prof_enter_radio(void) { @@ -65,6 +100,12 @@ void lll_prof_exit_radio(void) { delta(timestamp_radio, &cputime_radio); delta_ticks(timestamp_ticks_radio, &cputime_ticks_radio); + LLL_PROF_ASSERT(cputime_ticks_radio, HAL_TICKER_US_TO_TICKS(LLL_PROF_RADIO_MAX_US)); +} + +uint16_t lll_prof_radio_get(void) +{ + return HAL_TICKER_TICKS_TO_US(cputime_ticks_radio); } void lll_prof_enter_lll(void) @@ -77,6 +118,12 @@ void lll_prof_exit_lll(void) { delta(timestamp_lll, &cputime_lll); delta_ticks(timestamp_ticks_lll, &cputime_ticks_lll); + LLL_PROF_ASSERT(cputime_ticks_lll, HAL_TICKER_US_TO_TICKS(LLL_PROF_LLL_MAX_US)); +} + +uint16_t lll_prof_lll_get(void) +{ + return HAL_TICKER_TICKS_TO_US(cputime_ticks_lll); } void lll_prof_enter_ull_high(void) @@ -89,6 +136,12 @@ void lll_prof_exit_ull_high(void) { delta(timestamp_ull_high, &cputime_ull_high); delta_ticks(timestamp_ticks_ull_high, &cputime_ticks_ull_high); + LLL_PROF_ASSERT(cputime_ticks_ull_high, HAL_TICKER_US_TO_TICKS(LLL_PROF_ULL_HIGH_MAX_US)); +} + +uint16_t lll_prof_ull_high_get(void) +{ + return HAL_TICKER_TICKS_TO_US(cputime_ticks_ull_high); } void lll_prof_enter_ull_low(void) @@ -101,6 +154,12 @@ void lll_prof_exit_ull_low(void) { delta(timestamp_ull_low, &cputime_ull_low); delta_ticks(timestamp_ticks_ull_low, &cputime_ticks_ull_low); + LLL_PROF_ASSERT(cputime_ticks_ull_low, HAL_TICKER_US_TO_TICKS(LLL_PROF_ULL_LOW_MAX_US)); +} + +uint16_t lll_prof_ull_low_get(void) +{ + return HAL_TICKER_TICKS_TO_US(cputime_ticks_ull_low); } void lll_prof_latency_capture(void) @@ -329,12 +388,12 @@ static inline void delta(uint32_t timestamp, uint16_t *cputime) } } -static inline void delta_ticks(uint32_t timestamp_ticks, uint8_t *cputime_ticks) +static inline void delta_ticks(uint32_t timestamp_ticks, uint16_t *cputime_ticks) { uint32_t delta; delta = ticker_ticks_now_get() - timestamp_ticks; - if (delta < UINT8_MAX && delta > *cputime_ticks) { + if (delta < UINT16_MAX && delta > *cputime_ticks) { *cputime_ticks = delta; } } diff --git a/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_prof_internal.h b/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_prof_internal.h index d5b3ba5f1f3d6..cddb50dbefcf1 100644 --- a/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_prof_internal.h +++ b/subsys/bluetooth/controller/ll_sw/nordic/lll/lll_prof_internal.h @@ -4,25 +4,18 @@ * SPDX-License-Identifier: Apache-2.0 */ -#if defined(CONFIG_BT_CTLR_PROFILE_ISR) void lll_prof_enter_radio(void); void lll_prof_exit_radio(void); +uint16_t lll_prof_radio_get(void); void lll_prof_enter_lll(void); void lll_prof_exit_lll(void); +uint16_t lll_prof_lll_get(void); void lll_prof_enter_ull_high(void); void lll_prof_exit_ull_high(void); +uint16_t lll_prof_ull_high_get(void); void lll_prof_enter_ull_low(void); void lll_prof_exit_ull_low(void); -#else -static inline void lll_prof_enter_radio(void) {} -static inline void lll_prof_exit_radio(void) {} -static inline void lll_prof_enter_lll(void) {} -static inline void lll_prof_exit_lll(void) {} -static inline void lll_prof_enter_ull_high(void) {} -static inline void lll_prof_exit_ull_high(void) {} -static inline void lll_prof_enter_ull_low(void) {} -static inline void lll_prof_exit_ull_low(void) {} -#endif +uint16_t lll_prof_ull_low_get(void); void lll_prof_latency_capture(void); uint16_t lll_prof_latency_get(void); diff --git a/subsys/bluetooth/controller/ll_sw/ull.c b/subsys/bluetooth/controller/ll_sw/ull.c index bf15820ecd6db..76f7e19465941 100644 --- a/subsys/bluetooth/controller/ll_sw/ull.c +++ b/subsys/bluetooth/controller/ll_sw/ull.c @@ -86,8 +86,16 @@ #include "ll_test.h" #include "ll_settings.h" +#include "lll/lll_prof_internal.h" + #include "hal/debug.h" +#define TEST_TICKER_NODES (TICKER_NODES) +#define TEST_TICKER_TICKS_SLOT_US 100000U +#define TEST_TICKER_INTERVAL_US (((TEST_TICKER_TICKS_SLOT_US) + \ + (HAL_TICKER_RESCHEDULE_MARGIN_US)) * \ + (TEST_TICKER_NODES)) + #if defined(CONFIG_BT_BROADCASTER) #define BT_ADV_TICKER_NODES ((TICKER_ID_ADV_LAST) - (TICKER_ID_ADV_STOP) + 1) #if defined(CONFIG_BT_CTLR_ADV_EXT) && (CONFIG_BT_CTLR_ADV_AUX_SET > 0) @@ -549,6 +557,16 @@ static MFIFO_DEFINE(tx_ack, sizeof(struct lll_tx), static void *mark_disable; +#if defined(CONFIG_BT_CTLR_TEST) +static struct k_sem sem_test_ticker; +static uint32_t test_ticker_latency_ticks; +static void test_ticker_cb(uint32_t ticks_at_expire, uint32_t ticks_drift, uint32_t remainder, + uint16_t lazy, uint8_t force, void *context); +#if defined(CONFIG_BT_TICKER_EXT) +static struct ticker_ext test_ticker_ext[TEST_TICKER_NODES]; +#endif /* CONFIG_BT_TICKER_EXT */ +#endif /* CONFIG_BT_CTLR_TEST */ + static inline int init_reset(void); static void perform_lll_reset(void *param); static inline void *mark_set(void **m, void *param); @@ -774,6 +792,65 @@ int ll_init(struct k_sem *sem_rx) return err; } + k_sem_init(&sem_test_ticker, 0, TEST_TICKER_NODES); + + const uint32_t ticks_now = ticker_ticks_now_get(); + + for (uint8_t ticker_id = 0U; ticker_id < TEST_TICKER_NODES; ticker_id++) { + uint32_t ret; + +#if defined(CONFIG_BT_TICKER_EXT) +#if !defined(CONFIG_BT_CTLR_JIT_SCHEDULING) + test_ticker_ext[ticker_id].ticks_slot_window = + HAL_TICKER_US_TO_TICKS((TEST_TICKER_INTERVAL_US) + + (TEST_TICKER_TICKS_SLOT_US)); +#endif /* !CONFIG_BT_CTLR_JIT_SCHEDULING */ + + ret = ticker_start_ext( +#else /* !CONFIG_BT_TICKER_EXT */ + ret = ticker_start( +#endif /* !CONFIG_BT_TICKER_EXT */ + TICKER_INSTANCE_ID_CTLR /* instance */ + , TICKER_USER_ID_THREAD /* user */ + , ticker_id /* ticker id */ + , ticks_now /* anchor point */ + , HAL_TICKER_US_TO_TICKS(TEST_TICKER_INTERVAL_US) /* first interval */ + , HAL_TICKER_US_TO_TICKS(TEST_TICKER_INTERVAL_US) /* periodic interval */ + , HAL_TICKER_REMAINDER(TEST_TICKER_INTERVAL_US) /* remainder */ + , 0 /* lazy */ + , HAL_TICKER_US_TO_TICKS(TEST_TICKER_TICKS_SLOT_US) /* slot */ + , test_ticker_cb /* timeout callback function */ + , (void *)(uint32_t)ticker_id /* context */ + , 0 /* op func */ + , 0 /* op context */ +#if defined(CONFIG_BT_TICKER_EXT) + , &test_ticker_ext[ticker_id] +#endif /* CONFIG_BT_TICKER_EXT */ + ); + LL_ASSERT(ret == TICKER_STATUS_SUCCESS); + } + + for (uint8_t ticker_id = 0U; ticker_id < TEST_TICKER_NODES; ticker_id++) { + k_sem_take(&sem_test_ticker, K_FOREVER); + } + + for (uint8_t ticker_id = 0U; ticker_id < TEST_TICKER_NODES; ticker_id++) { + uint32_t ret; + + ret = ticker_stop(TICKER_INSTANCE_ID_CTLR, + TICKER_USER_ID_THREAD, + ticker_id, + NULL, + NULL); + LL_ASSERT(ret == TICKER_STATUS_SUCCESS); + } + + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR)) { + printk("%s: Radio %u, LLL %u, ULL_HIGH %u, ULL_LOW %u, Latency %u.\n", + __func__, lll_prof_radio_get(), lll_prof_lll_get(), lll_prof_ull_high_get(), + lll_prof_ull_low_get(), HAL_TICKER_TICKS_TO_US(test_ticker_latency_ticks)); + } + #if defined(CONFIG_BT_CTLR_CHAN_SEL_2) lll_chan_sel_2_ut(); #endif /* CONFIG_BT_CTLR_CHAN_SEL_2 */ @@ -2372,6 +2449,30 @@ void ull_drift_ticks_get(struct node_rx_event_done *done, } #endif /* CONFIG_BT_PERIPHERAL || CONFIG_BT_CTLR_SYNC_PERIODIC */ +#if defined(CONFIG_BT_CTLR_TEST) +static void test_ticker_cb(uint32_t ticks_at_expire, uint32_t ticks_drift, uint32_t remainder, + uint16_t lazy, uint8_t force, void *context) +{ + uint32_t ticks_latency; + uint32_t ticks_now; + + ticks_now = ticker_ticks_now_get(); + ticks_latency = ticker_ticks_diff_get(ticks_now, ticks_at_expire); + if (ticks_latency > test_ticker_latency_ticks) { + test_ticker_latency_ticks = ticks_latency; + } + + if (IS_ENABLED(CONFIG_BT_CTLR_PROFILE_ISR) && IS_ENABLED(CONFIG_LOG_PRINTK)) { + printk("%s: %u/%u at %u + %u + %u us (ULL_LOW %u us)\n", __func__, + (uint32_t)context, TEST_TICKER_NODES, + HAL_TICKER_TICKS_TO_US(ticks_at_expire), HAL_TICKER_TICKS_TO_US(ticks_drift), + HAL_TICKER_TICKS_TO_US(ticks_latency), lll_prof_ull_low_get()); + } + + k_sem_give(&sem_test_ticker); +} +#endif /* CONFIG_BT_CTLR_TEST */ + static inline int init_reset(void) { memq_link_t *link;