From d73572eb4a61e4f821ed741be6036a9e2310aca3 Mon Sep 17 00:00:00 2001 From: Andrzej Kaczmarek Date: Mon, 21 May 2018 12:57:00 +0200 Subject: [PATCH] nimble/ll: Use logging via sysview This patch removes current logging from LL/PHY (which is temporary only anyway) and replaces it by sysview tracing. This allows to see traces together with ISRs and tasks activity. --- nimble/controller/include/controller/ble_ll.h | 31 ------ .../include/controller/ble_ll_trace.h | 92 ++++++++++++++++ .../include/controller/ble_phy_trace.h | 94 ++++++++++++++++ nimble/controller/src/ble_ll.c | 101 +++--------------- nimble/controller/src/ble_ll_adv.c | 13 ++- nimble/controller/src/ble_ll_conn.c | 38 +++---- nimble/controller/src/ble_ll_ctrl.c | 3 +- nimble/controller/src/ble_ll_scan.c | 1 - nimble/controller/src/ble_ll_sched.c | 7 +- nimble/controller/src/ble_ll_trace.c | 53 +++++++++ nimble/controller/src/ble_ll_xcvr.c | 4 - nimble/controller/syscfg.yml | 5 + nimble/drivers/nrf51/src/ble_phy.c | 17 ++- nimble/drivers/nrf52/src/ble_phy.c | 18 ++-- nimble/drivers/nrf52/src/ble_phy_trace.c | 44 ++++++++ nimble/drivers/nrf52/syscfg.yml | 5 + 16 files changed, 355 insertions(+), 171 deletions(-) create mode 100644 nimble/controller/include/controller/ble_ll_trace.h create mode 100644 nimble/controller/include/controller/ble_phy_trace.h create mode 100644 nimble/controller/src/ble_ll_trace.c create mode 100644 nimble/drivers/nrf52/src/ble_phy_trace.c diff --git a/nimble/controller/include/controller/ble_ll.h b/nimble/controller/include/controller/ble_ll.h index dc917dbe1..255bad6ec 100644 --- a/nimble/controller/include/controller/ble_ll.h +++ b/nimble/controller/include/controller/ble_ll.h @@ -490,37 +490,6 @@ ble_ll_usecs_to_ticks_round_up(uint32_t usecs) return os_cputime_usecs_to_ticks(usecs + 30); } -#define BLE_LL_LOG_ID_PHY_SETCHAN (1) -#define BLE_LL_LOG_ID_RX_START (2) -#define BLE_LL_LOG_ID_RX_END (3) -#define BLE_LL_LOG_ID_WFR_EXP (4) -#define BLE_LL_LOG_ID_PHY_TXEND (5) -#define BLE_LL_LOG_ID_PHY_TX (6) -#define BLE_LL_LOG_ID_PHY_RX (7) -#define BLE_LL_LOG_ID_PHY_DISABLE (9) -#define BLE_LL_LOG_ID_CONN_EV_START (10) -#define BLE_LL_LOG_ID_CONN_TX (15) -#define BLE_LL_LOG_ID_CONN_RX (16) -#define BLE_LL_LOG_ID_CONN_TX_RETRY (17) -#define BLE_LL_LOG_ID_CONN_RX_ACK (18) -#define BLE_LL_LOG_ID_LL_CTRL_RX (19) -#define BLE_LL_LOG_ID_CONN_EV_END (20) -#define BLE_LL_LOG_ID_CONN_END (30) -#define BLE_LL_LOG_ID_ADV_TXBEG (50) -#define BLE_LL_LOG_ID_ADV_TXDONE (60) -#define BLE_LL_LOG_ID_SCHED (80) -#define BLE_LL_LOG_ID_RFCLK_START (90) -#define BLE_LL_LOG_ID_RFCLK_ENABLE (91) -#define BLE_LL_LOG_ID_RFCLK_STOP (95) -#define BLE_LL_LOG_ID_RFCLK_SCHED_DIS (96) -#define BLE_LL_LOG_ID_RFCLK_SCAN_DIS (97) - -#ifdef BLE_LL_LOG -void ble_ll_log(uint8_t id, uint8_t arg8, uint16_t arg16, uint32_t arg32); -#else -#define ble_ll_log(m,n,o,p) -#endif - #if (MYNEWT_VAL(BLE_LL_CFG_FEAT_LE_ENCRYPTION) == 1) /* LTK 0x4C68384139F574D836BCF34E9DFB01BF */ extern const uint8_t g_bletest_LTK[]; diff --git a/nimble/controller/include/controller/ble_ll_trace.h b/nimble/controller/include/controller/ble_ll_trace.h new file mode 100644 index 000000000..493bd667a --- /dev/null +++ b/nimble/controller/include/controller/ble_ll_trace.h @@ -0,0 +1,92 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +#ifndef H_BLE_LL_TRACE_ +#define H_BLE_LL_TRACE_ + +#ifdef __cplusplus +extern "C" { +#endif + +#define BLE_LL_TRACE_ID_SCHED 0 +#define BLE_LL_TRACE_ID_RX_START 1 +#define BLE_LL_TRACE_ID_RX_END 2 +#define BLE_LL_TRACE_ID_WFR_EXP 3 +#define BLE_LL_TRACE_ID_CTRL_RX 4 +#define BLE_LL_TRACE_ID_CONN_EV_START 5 +#define BLE_LL_TRACE_ID_CONN_EV_END 6 +#define BLE_LL_TRACE_ID_CONN_END 7 +#define BLE_LL_TRACE_ID_CONN_TX 8 +#define BLE_LL_TRACE_ID_CONN_RX 9 +#define BLE_LL_TRACE_ID_ADV_TXDONE 10 +#define BLE_LL_TRACE_ID_ADV_HALT 11 + +#if MYNEWT_VAL(BLE_LL_SYSVIEW) + +extern uint32_t ble_ll_trace_off; + +void ble_ll_trace_init(void); + +static inline void +ble_ll_trace_u32(unsigned id, uint32_t p1) +{ + os_trace_api_u32(ble_ll_trace_off + id, p1); +} + +static inline void +ble_ll_trace_u32x2(unsigned id, uint32_t p1, uint32_t p2) +{ + os_trace_api_u32x2(ble_ll_trace_off + id, p1, p2); +} + +static inline void +ble_ll_trace_u32x3(unsigned id, uint32_t p1, uint32_t p2, uint32_t p3) +{ + os_trace_api_u32x3(ble_ll_trace_off + id, p1, p2, p3); +} + +#else + +static inline void +ble_ll_trace_init(void) +{ +} + +static inline void +ble_ll_trace_u32(unsigned id, uint32_t p1) +{ +} + +static inline void +ble_ll_trace_u32x2(unsigned id, uint32_t p1, uint32_t p2) +{ +} + +static inline void +ble_ll_trace_u32x3(unsigned id, uint32_t p1, uint32_t p2, uint32_t p3) +{ +} + +#endif + +#ifdef __cplusplus +} +#endif + +#endif /* H_BLE_LL_TRACE_ */ diff --git a/nimble/controller/include/controller/ble_phy_trace.h b/nimble/controller/include/controller/ble_phy_trace.h new file mode 100644 index 000000000..5a3f03149 --- /dev/null +++ b/nimble/controller/include/controller/ble_phy_trace.h @@ -0,0 +1,94 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +#ifndef H_BLE_PHY_TRACE_ +#define H_BLE_PHY_TRACE_ + +#ifdef __cplusplus +extern "C" { +#endif + +#define BLE_PHY_TRACE_ID_START_TX 0 +#define BLE_PHY_TRACE_ID_START_RX 1 +#define BLE_PHY_TRACE_ID_DISABLE 2 + +#if MYNEWT_VAL(BLE_PHY_SYSVIEW) + +extern uint32_t ble_phy_trace_off; + +void ble_phy_trace_init(void); + +static inline void +ble_phy_trace_void(unsigned id) +{ + os_trace_api_void(ble_phy_trace_off + id); +} + +static inline void +ble_phy_trace_u32(unsigned id, uint32_t p1) +{ + os_trace_api_u32(ble_phy_trace_off + id, p1); +} + +static inline void +ble_phy_trace_u32x2(unsigned id, uint32_t p1, uint32_t p2) +{ + os_trace_api_u32x2(ble_phy_trace_off + id, p1, p2); +} + +static inline void +ble_phy_trace_u32x3(unsigned id, uint32_t p1, uint32_t p2, uint32_t p3) +{ + os_trace_api_u32x3(ble_phy_trace_off + id, p1, p2, p3); +} + +#else + +static inline void +ble_phy_trace_init(void) +{ +} + +static inline void +ble_phy_trace_void(unsigned id) +{ +} + +static inline void +ble_phy_trace_u32(unsigned id, uint32_t p1) +{ +} + +static inline void +ble_phy_trace_u32x2(unsigned id, uint32_t p1, uint32_t p2) +{ +} + +static inline void +ble_phy_trace_u32x3(unsigned id, uint32_t p1, uint32_t p2, uint32_t p3) +{ +} + +#endif + +#ifdef __cplusplus +} +#endif + +#endif /* H_BLE_PHY_TRACE_ */ diff --git a/nimble/controller/src/ble_ll.c b/nimble/controller/src/ble_ll.c index 87317eccd..b2257fa19 100644 --- a/nimble/controller/src/ble_ll.c +++ b/nimble/controller/src/ble_ll.c @@ -32,6 +32,7 @@ #include "nimble/ble_hci_trans.h" #include "controller/ble_hw.h" #include "controller/ble_phy.h" +#include "controller/ble_phy_trace.h" #include "controller/ble_ll.h" #include "controller/ble_ll_adv.h" #include "controller/ble_ll_sched.h" @@ -40,6 +41,7 @@ #include "controller/ble_ll_whitelist.h" #include "controller/ble_ll_resolv.h" #include "controller/ble_ll_xcvr.h" +#include "controller/ble_ll_trace.h" #include "ble_ll_conn_priv.h" #if MYNEWT_VAL(BLE_LL_DIRECT_TEST_MODE) == 1 @@ -249,44 +251,6 @@ static const uint16_t g_ble_ll_pdu_header_tx_time[BLE_PHY_NUM_MODE] = (80 + 256 + 16 + 24 + 2 * (BLE_LL_PDU_HDR_LEN * 8 + 24 + 3)), }; -/* XXX: temporary logging until we transition to real logging */ -#ifdef BLE_LL_LOG -struct ble_ll_log -{ - uint8_t log_id; - uint8_t log_a8; - uint16_t log_a16; - uint32_t log_a32; - uint32_t cputime; - -}; - -#define BLE_LL_LOG_LEN (256) - -static bssnz_t struct ble_ll_log g_ble_ll_log[BLE_LL_LOG_LEN]; -static uint8_t g_ble_ll_log_index; - -void -ble_ll_log(uint8_t id, uint8_t arg8, uint16_t arg16, uint32_t arg32) -{ - os_sr_t sr; - struct ble_ll_log *le; - - OS_ENTER_CRITICAL(sr); - le = &g_ble_ll_log[g_ble_ll_log_index]; - le->cputime = os_cputime_get32(); - le->log_id = id; - le->log_a8 = arg8; - le->log_a16 = arg16; - le->log_a32 = arg32; - ++g_ble_ll_log_index; - if (g_ble_ll_log_index == BLE_LL_LOG_LEN) { - g_ble_ll_log_index = 0; - } - OS_EXIT_CRITICAL(sr); -} -#endif - /** * Counts the number of advertising PDU's received, by type. For advertising * PDU's that contain a destination address, we still count these packets even @@ -578,8 +542,8 @@ ble_ll_wfr_timer_exp(void *arg) rx_start = ble_phy_rx_started(); lls = g_ble_ll_data.ll_state; - ble_ll_log(BLE_LL_LOG_ID_WFR_EXP, lls, ble_phy_xcvr_state_get(), - (uint32_t)rx_start); + ble_ll_trace_u32x3(BLE_LL_TRACE_ID_WFR_EXP, lls, ble_phy_xcvr_state_get(), + (uint32_t)rx_start); /* If we have started a reception, there is nothing to do here */ if (!rx_start) { @@ -880,14 +844,14 @@ ble_ll_rx_start(uint8_t *rxbuf, uint8_t chan, struct ble_mbuf_hdr *rxhdr) int rc; uint8_t pdu_type; - ble_ll_log(BLE_LL_LOG_ID_RX_START, chan, rxhdr->rem_usecs, - rxhdr->beg_cputime); - /* Advertising channel PDU */ pdu_type = rxbuf[0] & BLE_ADV_PDU_HDR_TYPE_MASK; + ble_ll_trace_u32x2(BLE_LL_TRACE_ID_RX_START, g_ble_ll_data.ll_state, + pdu_type); + switch (g_ble_ll_data.ll_state) { - case BLE_LL_STATE_CONNECTION: + case BLE_LL_STATE_CONNECTION: rc = ble_ll_conn_rx_isr_start(rxhdr, ble_phy_access_addr_get()); break; case BLE_LL_STATE_ADV: @@ -940,9 +904,12 @@ ble_ll_rx_end(uint8_t *rxbuf, struct ble_mbuf_hdr *rxhdr) /* Get CRC status from BLE header */ crcok = BLE_MBUF_HDR_CRC_OK(rxhdr); - ble_ll_log(BLE_LL_LOG_ID_RX_END, rxbuf[0], - ((uint16_t)rxhdr->rxinfo.flags << 8) | rxbuf[1], - rxhdr->beg_cputime); + /* Get advertising PDU type and length */ + pdu_type = rxbuf[0] & BLE_ADV_PDU_HDR_TYPE_MASK; + len = rxbuf[1]; + + ble_ll_trace_u32x3(BLE_LL_TRACE_ID_RX_END, pdu_type, len, + rxhdr->rxinfo.flags); #if MYNEWT_VAL(BLE_LL_DIRECT_TEST_MODE) == 1 if (BLE_MBUF_HDR_RX_STATE(rxhdr) == BLE_LL_STATE_DTM) { @@ -956,10 +923,6 @@ ble_ll_rx_end(uint8_t *rxbuf, struct ble_mbuf_hdr *rxhdr) return rc; } - /* Get advertising PDU type and length */ - pdu_type = rxbuf[0] & BLE_ADV_PDU_HDR_TYPE_MASK; - len = rxbuf[1]; - /* If the CRC checks, make sure lengths check! */ badpkt = 0; if (crcok) { @@ -1263,11 +1226,6 @@ ble_ll_reset(void) /* Reset LL stats */ STATS_RESET(ble_ll_stats); -#ifdef BLE_LL_LOG - g_ble_ll_log_index = 0; - memset(&g_ble_ll_log, 0, sizeof(g_ble_ll_log)); -#endif - /* Reset any preferred PHYs */ g_ble_ll_data.ll_pref_tx_phys = 0; g_ble_ll_data.ll_pref_rx_phys = 0; @@ -1421,6 +1379,9 @@ ble_ll_init(void) /* Ensure this function only gets called by sysinit. */ SYSINIT_ASSERT_ACTIVE(); + ble_ll_trace_init(); + ble_phy_trace_init(); + /* Retrieve the public device address if not set by syscfg */ memcpy(&addr.val[0], MYNEWT_VAL_BLE_PUBLIC_DEV_ADDR, BLE_DEV_ADDR_LEN); if (!memcmp(&addr.val[0], ((ble_addr_t *)BLE_ADDR_ANY)->val, @@ -1562,31 +1523,3 @@ ble_ll_init(void) ble_hci_trans_cfg_ll(ble_ll_hci_cmd_rx, NULL, ble_ll_hci_acl_rx, NULL); } - -#ifdef BLE_LL_LOG -void -ble_ll_log_dump_index(int i) -{ - struct ble_ll_log *log; - - log = &g_ble_ll_log[i]; - - /* TODO cast is a workaround until this is fixed properly */ - console_printf("cputime=%lu id=%u a8=%u a16=%u a32=%lu\n", - (unsigned long)log->cputime, log->log_id, log->log_a8, - log->log_a16, (unsigned long)log->log_a32); -} - -void -ble_ll_log_dump(void) -{ - int i; - - for (i = g_ble_ll_log_index; i < BLE_LL_LOG_LEN; ++i) { - ble_ll_log_dump_index(i); - } - for (i = 0; i < g_ble_ll_log_index; ++i) { - ble_ll_log_dump_index(i); - } -} -#endif diff --git a/nimble/controller/src/ble_ll_adv.c b/nimble/controller/src/ble_ll_adv.c index 3fa0c7706..0935b58c6 100644 --- a/nimble/controller/src/ble_ll_adv.c +++ b/nimble/controller/src/ble_ll_adv.c @@ -36,6 +36,7 @@ #include "controller/ble_ll_scan.h" #include "controller/ble_ll_whitelist.h" #include "controller/ble_ll_resolv.h" +#include "controller/ble_ll_trace.h" #include "ble_ll_conn_priv.h" /* XXX: TODO @@ -791,6 +792,9 @@ ble_ll_adv_tx_done(void *arg) advsm = (struct ble_ll_adv_sm *)arg; + ble_ll_trace_u32x2(BLE_LL_TRACE_ID_ADV_TXDONE, advsm->adv_instance, + advsm->flags & BLE_LL_ADV_SM_FLAG_ACTIVE_CHANSET_MASK); + #if MYNEWT_VAL(BLE_LL_CFG_FEAT_LL_EXT_ADV) if (ble_ll_adv_active_chanset_is_pri(advsm)) { ble_npl_eventq_put(&g_ble_ll_data.ll_evq, &advsm->adv_txdone_ev); @@ -804,9 +808,6 @@ ble_ll_adv_tx_done(void *arg) ble_npl_eventq_put(&g_ble_ll_data.ll_evq, &advsm->adv_txdone_ev); #endif - ble_ll_log(BLE_LL_LOG_ID_ADV_TXDONE, ble_ll_state_get(), - advsm->adv_instance, 0); - ble_ll_state_set(BLE_LL_STATE_STANDBY); ble_ll_adv_active_chanset_clear(advsm); @@ -1372,6 +1373,8 @@ ble_ll_adv_halt(void) if (g_ble_ll_cur_adv_sm != NULL) { advsm = g_ble_ll_cur_adv_sm; + ble_ll_trace_u32(BLE_LL_TRACE_ID_ADV_HALT, advsm->adv_instance); + ble_phy_txpwr_set(MYNEWT_VAL(BLE_LL_TX_PWR_DBM)); ble_npl_eventq_put(&g_ble_ll_data.ll_evq, &advsm->adv_txdone_ev); @@ -1381,11 +1384,11 @@ ble_ll_adv_halt(void) } #endif - ble_ll_log(BLE_LL_LOG_ID_ADV_TXDONE, ble_ll_state_get(), - advsm->adv_instance, 0); ble_ll_state_set(BLE_LL_STATE_STANDBY); ble_ll_adv_active_chanset_clear(g_ble_ll_cur_adv_sm); g_ble_ll_cur_adv_sm = NULL; + } else { + ble_ll_trace_u32(BLE_LL_TRACE_ID_ADV_HALT, UINT32_MAX); } } diff --git a/nimble/controller/src/ble_ll_conn.c b/nimble/controller/src/ble_ll_conn.c index e868d0fac..63c4d1381 100644 --- a/nimble/controller/src/ble_ll_conn.c +++ b/nimble/controller/src/ble_ll_conn.c @@ -37,6 +37,7 @@ #include "controller/ble_ll_ctrl.h" #include "controller/ble_ll_resolv.h" #include "controller/ble_ll_adv.h" +#include "controller/ble_ll_trace.h" #include "controller/ble_phy.h" #include "controller/ble_hw.h" #include "ble_ll_conn_priv.h" @@ -1387,10 +1388,8 @@ conn_tx_pdu: if (!rc) { /* Log transmit on connection state */ cur_txlen = ble_hdr->txinfo.pyld_len; - ble_ll_log(BLE_LL_LOG_ID_CONN_TX, - hdr_byte, - ((uint16_t)ble_hdr->txinfo.offset << 8) | cur_txlen, - (uint32_t)m); + ble_ll_trace_u32x2(BLE_LL_TRACE_ID_CONN_TX, cur_txlen, + ble_hdr->txinfo.offset); /* Set last transmitted MD bit */ CONN_F_LAST_TXD_MD(connsm) = md; @@ -1433,16 +1432,15 @@ ble_ll_conn_event_start_cb(struct ble_ll_sched_item *sch) g_ble_ll_conn_cur_sm = connsm; assert(connsm); + /* Log connection event start */ + ble_ll_trace_u32(BLE_LL_TRACE_ID_CONN_EV_START, connsm->conn_handle); + /* Disable whitelisting as connections do not use it */ ble_ll_whitelist_disable(); /* Set LL state */ ble_ll_state_set(BLE_LL_STATE_CONNECTION); - /* Log connection event start */ - ble_ll_log(BLE_LL_LOG_ID_CONN_EV_START, (uint8_t)connsm->conn_handle, - (uint16_t)connsm->ce_end_time, connsm->csmflags.conn_flags); - /* Set channel */ ble_phy_setchan(connsm->data_chan_index, connsm->access_addr, connsm->crcinit); @@ -2184,8 +2182,8 @@ ble_ll_conn_end(struct ble_ll_conn_sm *connsm, uint8_t ble_err) STAILQ_INSERT_TAIL(&g_ble_ll_conn_free_list, connsm, free_stqe); /* Log connection end */ - ble_ll_log(BLE_LL_LOG_ID_CONN_END,connsm->conn_handle, ble_err, - connsm->event_cntr); + ble_ll_trace_u32x3(BLE_LL_TRACE_ID_CONN_END, connsm->conn_handle, + connsm->event_cntr, (uint32_t)ble_err); } /** @@ -2565,6 +2563,10 @@ ble_ll_conn_event_end(struct ble_npl_event *ev) connsm = (struct ble_ll_conn_sm *)ble_npl_event_get_arg(ev); assert(connsm); + /* Log event end */ + ble_ll_trace_u32x2(BLE_LL_TRACE_ID_CONN_EV_END, connsm->conn_handle, + connsm->event_cntr); + /* Check if we need to resume scanning */ ble_ll_scan_chk_resume(); @@ -2669,10 +2671,6 @@ ble_ll_conn_event_end(struct ble_npl_event *ev) return; } - /* Log event end */ - ble_ll_log(BLE_LL_LOG_ID_CONN_EV_END, connsm->conn_handle, - connsm->event_cntr, connsm->conn_sch.start_time); - /* If we have completed packets, send an event */ ble_ll_conn_num_comp_pkts_event_send(connsm); @@ -3744,16 +3742,8 @@ ble_ll_conn_rx_isr_end(uint8_t *rxbuf, struct ble_mbuf_hdr *rxhdr) #endif } -#if MYNEWT_VAL(BLE_LL_CFG_FEAT_LE_ENCRYPTION) - ble_ll_log(BLE_LL_LOG_ID_CONN_RX, - hdr_byte, - (uint16_t)connsm->tx_seqnum << 8 | conn_nesn, - connsm->enc_data.rx_pkt_cntr); -#else - ble_ll_log(BLE_LL_LOG_ID_CONN_RX, - hdr_byte, - (uint16_t)connsm->tx_seqnum << 8 | conn_nesn, 0); -#endif + ble_ll_trace_u32x2(BLE_LL_TRACE_ID_CONN_RX, connsm->tx_seqnum, + !!(hdr_byte & BLE_LL_DATA_HDR_NESN_MASK)); /* * Check NESN bit from header. If same as tx seq num, the transmission diff --git a/nimble/controller/src/ble_ll_ctrl.c b/nimble/controller/src/ble_ll_ctrl.c index 895eecc02..bc435b986 100644 --- a/nimble/controller/src/ble_ll_ctrl.c +++ b/nimble/controller/src/ble_ll_ctrl.c @@ -26,6 +26,7 @@ #include "controller/ble_ll.h" #include "controller/ble_ll_hci.h" #include "controller/ble_ll_ctrl.h" +#include "controller/ble_ll_trace.h" #include "controller/ble_hw.h" #include "ble_ll_conn_priv.h" @@ -2114,7 +2115,7 @@ ble_ll_ctrl_rx_pdu(struct ble_ll_conn_sm *connsm, struct os_mbuf *om) */ --len; - ble_ll_log(BLE_LL_LOG_ID_LL_CTRL_RX, opcode, len, 0); + ble_ll_trace_u32x2(BLE_LL_TRACE_ID_CTRL_RX, opcode, len); #if (MYNEWT_VAL(BLE_LL_CFG_FEAT_LE_ENCRYPTION) == 1) restart_encryption = 0; diff --git a/nimble/controller/src/ble_ll_scan.c b/nimble/controller/src/ble_ll_scan.c index 6b5ed5d95..e9a33b73f 100644 --- a/nimble/controller/src/ble_ll_scan.c +++ b/nimble/controller/src/ble_ll_scan.c @@ -1054,7 +1054,6 @@ ble_ll_scan_rfclk_chk_stop(void) stop = 1; } if (stop) { - ble_ll_log(BLE_LL_LOG_ID_RFCLK_SCAN_DIS, g_ble_ll_data.ll_rfclk_state,0,0); ble_ll_xcvr_rfclk_disable(); } OS_EXIT_CRITICAL(sr); diff --git a/nimble/controller/src/ble_ll_sched.c b/nimble/controller/src/ble_ll_sched.c index 7f0c1a4a4..ba713b397 100644 --- a/nimble/controller/src/ble_ll_sched.c +++ b/nimble/controller/src/ble_ll_sched.c @@ -29,6 +29,7 @@ #include "controller/ble_ll_adv.h" #include "controller/ble_ll_scan.h" #include "controller/ble_ll_xcvr.h" +#include "controller/ble_ll_trace.h" #include "ble_ll_conn_priv.h" /* XXX: this is temporary. Not sure what I want to do here */ @@ -1113,6 +1114,10 @@ ble_ll_sched_execute_item(struct ble_ll_sched_item *sch) uint8_t lls; lls = ble_ll_state_get(); + + ble_ll_trace_u32x3(BLE_LL_TRACE_ID_SCHED, lls, os_cputime_get32(), + sch->start_time); + if (lls == BLE_LL_STATE_STANDBY) { goto sched; } @@ -1264,8 +1269,6 @@ ble_ll_sched_rfclk_chk_restart(void) /* Only disable the rfclk if doing nothing */ if (ll_state == BLE_LL_STATE_STANDBY) { - ble_ll_log(BLE_LL_LOG_ID_RFCLK_SCHED_DIS, g_ble_ll_data.ll_rfclk_state, - 0, 0); ble_ll_xcvr_rfclk_disable(); } } diff --git a/nimble/controller/src/ble_ll_trace.c b/nimble/controller/src/ble_ll_trace.c new file mode 100644 index 000000000..bdea2bf8a --- /dev/null +++ b/nimble/controller/src/ble_ll_trace.c @@ -0,0 +1,53 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +#include +#include "syscfg/syscfg.h" +#include "os/os_trace_api.h" + +#if MYNEWT_VAL(BLE_LL_SYSVIEW) + +static os_trace_module_t g_ble_ll_trace_mod; +uint32_t ble_ll_trace_off; + +static void +ble_ll_trace_module_send_desc(void) +{ + os_trace_module_desc(&g_ble_ll_trace_mod, "0 ll_sched lls=%u cputime=%u start_time=%u"); + os_trace_module_desc(&g_ble_ll_trace_mod, "1 ll_rx_start lls=%u pdu_type=%x"); + os_trace_module_desc(&g_ble_ll_trace_mod, "2 ll_rx_end pdu_type=%x len=%u flags=%x"); + os_trace_module_desc(&g_ble_ll_trace_mod, "3 ll_wfr_timer_exp lls=%u xcvr=%u rx_start=%u"); + os_trace_module_desc(&g_ble_ll_trace_mod, "4 ll_ctrl_rx opcode=%u len=%u"); + os_trace_module_desc(&g_ble_ll_trace_mod, "5 ll_conn_ev_start conn_handle=%u"); + os_trace_module_desc(&g_ble_ll_trace_mod, "6 ll_conn_ev_end conn_handle=%u event_cntr=%u"); + os_trace_module_desc(&g_ble_ll_trace_mod, "7 ll_conn_end conn_handle=%u event_cntr=%u err=%u"); + os_trace_module_desc(&g_ble_ll_trace_mod, "8 ll_conn_tx len=%u offset=%u"); + os_trace_module_desc(&g_ble_ll_trace_mod, "9 ll_conn_rx conn_sn=%u pdu_nesn=%u"); + os_trace_module_desc(&g_ble_ll_trace_mod, "10 ll_adv_txdone inst=%u chanset=%x"); + os_trace_module_desc(&g_ble_ll_trace_mod, "11 ll_adv_halt inst=%u"); +} + +void +ble_ll_trace_init(void) +{ + ble_ll_trace_off = + os_trace_module_register(&g_ble_ll_trace_mod, "ble_ll", 12, + ble_ll_trace_module_send_desc); +} +#endif diff --git a/nimble/controller/src/ble_ll_xcvr.c b/nimble/controller/src/ble_ll_xcvr.c index ca420e4be..e61b7e89d 100644 --- a/nimble/controller/src/ble_ll_xcvr.c +++ b/nimble/controller/src/ble_ll_xcvr.c @@ -60,7 +60,6 @@ ble_ll_xcvr_rfclk_disable(void) void ble_ll_xcvr_rfclk_stop(void) { - ble_ll_log(BLE_LL_LOG_ID_RFCLK_STOP, g_ble_ll_data.ll_rfclk_state, 0,0); os_cputime_timer_stop(&g_ble_ll_data.ll_rfclk_timer); ble_ll_xcvr_rfclk_disable(); } @@ -113,7 +112,6 @@ ble_ll_xcvr_rfclk_start_now(uint32_t now) { ble_ll_xcvr_rfclk_enable(); g_ble_ll_data.ll_rfclk_start_time = now; - ble_ll_log(BLE_LL_LOG_ID_RFCLK_ENABLE, 0, 0, now); } /** @@ -149,7 +147,5 @@ ble_ll_xcvr_rfclk_timer_start(uint32_t cputime) os_cputime_timer_stop(&g_ble_ll_data.ll_rfclk_timer); } os_cputime_timer_start(&g_ble_ll_data.ll_rfclk_timer, cputime); - ble_ll_log(BLE_LL_LOG_ID_RFCLK_START, g_ble_ll_data.ll_rfclk_state, 0, - g_ble_ll_data.ll_rfclk_timer.expiry); } #endif diff --git a/nimble/controller/syscfg.yml b/nimble/controller/syscfg.yml index 8a89a12d3..f159d50df 100644 --- a/nimble/controller/syscfg.yml +++ b/nimble/controller/syscfg.yml @@ -35,6 +35,11 @@ syscfg.defs: Used to enable hardware white list value: 1 + BLE_LL_SYSVIEW: + description: > + Enable SystemView tracing module for controller. + value: 0 + BLE_LL_PRIO: description: 'The priority of the LL task' type: 'task_priority' diff --git a/nimble/drivers/nrf51/src/ble_phy.c b/nimble/drivers/nrf51/src/ble_phy.c index 5ea516234..6b6097f68 100644 --- a/nimble/drivers/nrf51/src/ble_phy.c +++ b/nimble/drivers/nrf51/src/ble_phy.c @@ -27,6 +27,7 @@ #include "nimble/ble.h" #include "nimble/nimble_opt.h" #include "controller/ble_phy.h" +#include "controller/ble_phy_trace.h" #include "controller/ble_ll.h" #include "nrfx.h" @@ -513,14 +514,11 @@ ble_phy_tx_end_isr(void) /* If this transmission was encrypted we need to remember it */ was_encrypted = g_ble_phy_data.phy_encrypted; + (void)was_encrypted; /* Better be in TX state! */ assert(g_ble_phy_data.phy_state == BLE_PHY_STATE_TX); - /* Log the event */ - ble_ll_log(BLE_LL_LOG_ID_PHY_TXEND, g_ble_phy_data.phy_tx_pyld_len, - was_encrypted, NRF_TIMER0->CC[2]); - /* Clear events and clear interrupt on disabled event */ NRF_RADIO->EVENTS_DISABLED = 0; NRF_RADIO->INTENCLR = RADIO_INTENCLR_DISABLED_Msk; @@ -956,8 +954,6 @@ ble_phy_rx(void) NRF_RADIO->TASKS_RXEN = 1; } - ble_ll_log(BLE_LL_LOG_ID_PHY_RX, g_ble_phy_data.phy_encrypted, 0, 0); - return 0; } @@ -1045,6 +1041,8 @@ ble_phy_tx_set_start_time(uint32_t cputime, uint8_t rem_usecs) { int rc; + ble_phy_trace_u32x2(BLE_PHY_TRACE_ID_START_TX, cputime, rem_usecs); + /* XXX: This should not be necessary, but paranoia is good! */ /* Clear timer0 compare to RXEN since we are transmitting */ NRF_PPI->CHENCLR = PPI_CHEN_CH21_Msk; @@ -1082,6 +1080,8 @@ ble_phy_rx_set_start_time(uint32_t cputime, uint8_t rem_usecs) { int rc; + ble_phy_trace_u32x2(BLE_PHY_TRACE_ID_START_RX, cputime, rem_usecs); + /* XXX: This should not be necessary, but paranoia is good! */ /* Clear timer0 compare to TXEN since we are transmitting */ NRF_PPI->CHENCLR = PPI_CHEN_CH20_Msk; @@ -1344,8 +1344,6 @@ ble_phy_setchan(uint8_t chan, uint32_t access_addr, uint32_t crcinit) NRF_RADIO->FREQUENCY = g_ble_phy_chan_freq[chan]; NRF_RADIO->DATAWHITEIV = chan; - ble_ll_log(BLE_LL_LOG_ID_PHY_SETCHAN, chan, freq, access_addr); - return 0; } @@ -1398,7 +1396,8 @@ ble_phy_restart_rx(void) void ble_phy_disable(void) { - ble_ll_log(BLE_LL_LOG_ID_PHY_DISABLE, g_ble_phy_data.phy_state, 0, 0); + ble_phy_trace_void(BLE_PHY_TRACE_ID_DISABLE); + ble_phy_stop_usec_timer(); ble_phy_disable_irq_and_ppi(); } diff --git a/nimble/drivers/nrf52/src/ble_phy.c b/nimble/drivers/nrf52/src/ble_phy.c index 819026449..fd6634ecb 100644 --- a/nimble/drivers/nrf52/src/ble_phy.c +++ b/nimble/drivers/nrf52/src/ble_phy.c @@ -27,6 +27,7 @@ #include "nimble/nimble_opt.h" #include "nimble/nimble_npl.h" #include "controller/ble_phy.h" +#include "controller/ble_phy_trace.h" #include "controller/ble_ll.h" #include "nrfx.h" #if MYNEWT @@ -806,15 +807,11 @@ ble_phy_tx_end_isr(void) /* If this transmission was encrypted we need to remember it */ was_encrypted = g_ble_phy_data.phy_encrypted; + (void)was_encrypted; /* Better be in TX state! */ assert(g_ble_phy_data.phy_state == BLE_PHY_STATE_TX); - /* Log the event */ - ble_ll_log(BLE_LL_LOG_ID_PHY_TXEND, g_ble_phy_data.phy_tx_pyld_len, - was_encrypted, NRF_TIMER0->CC[2]); - (void)was_encrypted; - /* Clear events and clear interrupt on disabled event */ NRF_RADIO->EVENTS_DISABLED = 0; NRF_RADIO->INTENCLR = RADIO_INTENCLR_DISABLED_Msk; @@ -1473,8 +1470,6 @@ ble_phy_rx(void) /* PPI to start radio automatically shall be set here */ assert(NRF_PPI->CHEN & PPI_CHEN_CH21_Msk); - ble_ll_log(BLE_LL_LOG_ID_PHY_RX, g_ble_phy_data.phy_encrypted, 0, 0); - return 0; } @@ -1552,6 +1547,8 @@ ble_phy_tx_set_start_time(uint32_t cputime, uint8_t rem_usecs) { int rc; + ble_phy_trace_u32x2(BLE_PHY_TRACE_ID_START_TX, cputime, rem_usecs); + /* XXX: This should not be necessary, but paranoia is good! */ /* Clear timer0 compare to RXEN since we are transmitting */ NRF_PPI->CHENCLR = PPI_CHEN_CH21_Msk; @@ -1587,6 +1584,8 @@ ble_phy_rx_set_start_time(uint32_t cputime, uint8_t rem_usecs) bool late = false; int rc = 0; + ble_phy_trace_u32x2(BLE_PHY_TRACE_ID_START_RX, cputime, rem_usecs); + /* XXX: This should not be necessary, but paranoia is good! */ /* Clear timer0 compare to TXEN since we are transmitting */ NRF_PPI->CHENCLR = PPI_CHEN_CH20_Msk; @@ -1848,8 +1847,6 @@ ble_phy_setchan(uint8_t chan, uint32_t access_addr, uint32_t crcinit) NRF_RADIO->FREQUENCY = g_ble_phy_chan_freq[chan]; NRF_RADIO->DATAWHITEIV = chan; - ble_ll_log(BLE_LL_LOG_ID_PHY_SETCHAN, chan, freq, access_addr); - return 0; } @@ -1907,7 +1904,8 @@ ble_phy_restart_rx(void) void ble_phy_disable(void) { - ble_ll_log(BLE_LL_LOG_ID_PHY_DISABLE, g_ble_phy_data.phy_state, 0, 0); + ble_phy_trace_void(BLE_PHY_TRACE_ID_DISABLE); + ble_phy_stop_usec_timer(); ble_phy_disable_irq_and_ppi(); } diff --git a/nimble/drivers/nrf52/src/ble_phy_trace.c b/nimble/drivers/nrf52/src/ble_phy_trace.c new file mode 100644 index 000000000..93b2eb326 --- /dev/null +++ b/nimble/drivers/nrf52/src/ble_phy_trace.c @@ -0,0 +1,44 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +#include +#include "syscfg/syscfg.h" +#include "os/os_trace_api.h" + +#if MYNEWT_VAL(BLE_PHY_SYSVIEW) + +static os_trace_module_t g_ble_phy_trace_mod; +uint32_t ble_phy_trace_off; + +static void +ble_phy_trace_module_send_desc(void) +{ + os_trace_module_desc(&g_ble_phy_trace_mod, "0 phy_set_tx cputime=%u usecs=%u"); + os_trace_module_desc(&g_ble_phy_trace_mod, "1 phy_set_rx cputime=%u usecs=%u"); + os_trace_module_desc(&g_ble_phy_trace_mod, "2 phy_disable"); +} + +void +ble_phy_trace_init(void) +{ + ble_phy_trace_off = + os_trace_module_register(&g_ble_phy_trace_mod, "ble_phy", 3, + ble_phy_trace_module_send_desc); +} +#endif diff --git a/nimble/drivers/nrf52/syscfg.yml b/nimble/drivers/nrf52/syscfg.yml index 3feb68bbc..da1222576 100644 --- a/nimble/drivers/nrf52/syscfg.yml +++ b/nimble/drivers/nrf52/syscfg.yml @@ -19,6 +19,11 @@ # Package: hw/drivers/nimble/nrf52 syscfg.defs: + BLE_PHY_SYSVIEW: + description: > + Enable SystemView tracing module for radio driver. + value: 0 + BLE_PHY_CODED_RX_IFS_EXTRA_MARGIN: description: > This defines additional margin for T_IFS tolerance while in