• State Verified Answer
  • +1 person also asked this people also asked this
  • Replies 18 replies
  • Subscribers 90 subscribers
  • Views 3930 views
  • Users 0 members are here
Attachments (0)
Nordic Case Info
  • Case ID: 264561
Options
This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

High current when using BLE NUS

rmakl

Hi,

I am starting to finalize a development stage and was looking at the current consumption of my device. I noticed, that when something connects to it and is starting to use the NUS service, current consumption skyrockets to 7mA and stays there, even after disconnecting every BLE connection.
This happens either:

  • I connect using Norduc UART Android App
  • I connect using nRF connect, then click on the TX Characteristic notification enable
  • I connect using a custom Android App that uses BLE NUS
  • Right after I make connection with the device (non-NUS) and my m_conn_handle becomes valid and I try to send data with ble_nus_data_send();

Here is an extract of an RTT log:

 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <debug> nrf_ble_gatt: Requesting to update ATT MTU to 158 bytes on connection 0x0.
 0> <debug> nrf_ble_gatt: ATT MTU updated to 158 bytes on connection 0x0 (response).
 0> <info> pwr_mgmt: CPU Usage: 0%
 0> <debug> nrf_ble_gatt: Peer on connection 0x0 requested a data length of 123 bytes.
 0> <debug> nrf_ble_gatt: Updating data length to 27 on connection 0x0.
 0> <debug> nrf_ble_gatt: Data length updated to 27 on connection 0x0.
 0> <debug> nrf_ble_gatt: max_rx_octets: 27
 0> <debug> nrf_ble_gatt: max_tx_octets: 27
 0> <debug> nrf_ble_gatt: max_rx_time: 1096
 0> <debug> nrf_ble_gatt: max_tx_time: 1096
 0> <info> app: BLE NUS connected
 0> <info> pwr_mgmt: CPU Usage: 4%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 39%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 38%
 0> <info> pwr_mgmt: CPU Usage: 38%

As you can see, CPU load is increased after NUS activity, but no other tasks are carried at that time.

What seems to be the problem?

I'm using:

  • s140_nrf52_7.0.1_softdevice.hex
  • nRF5_SDK_for_Thread_and_Zigbee_v4.1.0_32ce5f8

Best Regards,

Roland

Parents
  • 0

    Hi Rolan,

    I do not immediately see how the NUS service implementation itself could cause this. The large increase in CPU usage is very interesting, though.  Have you been able to see which part of your code is being run during this time? Perhaps just testing without optimization and pausing execution from a debugger could give some interesting observations on where time is being spent? If that does not provide any clues, can you share your code so that I can take a look?

    Einar

  • 0 in reply to Einar Thorsrud

    I edited made some modifications:

    #define NRF_SDH_BLE_GAP_DATA_LENGTH 251

    and

    /**
 * @brief 
 * 
 * @param p_context 
 */
void sensor_list_timeout_evt_handler(void *p_context)
{
	ret_code_t err_code;
	uint16_t length = 0;
	char str[512];
	size_t ptr = 0;

	if (m_conn_handle == BLE_CONN_HANDLE_INVALID || m_nus_connected == false) {
		return;
	}

	str[0] = '#';
	ptr = 1;
	for (int i = 0; i < ARRAY_SIZE(m_sim_datapoints); i++) {
		if (i > 0) {
			str[ptr] = ';';
			ptr++;
		}

		ptr += sprintf(&str[ptr], "%s,%d,%2.2f",
			m_sim_datapoints[i].name,
			m_sim_datapoints[i].enabled == true ? 1 : 0,
			m_sim_datapoints[i].values[m_sim_datapoints[i].index]);
	}

	length = ptr;
	str[ptr] = '\0';
	NRF_LOG_INFO("strlen: %d", length);

	err_code = ble_nus_data_send(&m_nus, str, &length, m_conn_handle);
	if ((err_code != NRF_ERROR_INVALID_STATE) &&
		(err_code != NRF_ERROR_RESOURCES) &&
		(err_code != NRF_ERROR_NOT_FOUND))
	{
		APP_ERROR_CHECK(err_code);
	}

	/*
	length = 5;
	err_code = ble_nus_data_send(&m_nus, "Hello", &length, m_conn_handle);
	if ((err_code != NRF_ERROR_INVALID_STATE) &&
		(err_code != NRF_ERROR_RESOURCES) &&
		(err_code != NRF_ERROR_NOT_FOUND))
	{
		//APP_ERROR_CHECK(err_code);
	}
	*/
}

    I print out the string length.

    Here is the RTT log:

    <info> pwr_mgmt: CPU Usage: 0%
<info> pwr_mgmt: CPU Usage: 0%
<info> pwr_mgmt: CPU Usage: 0%
<info> pwr_mgmt: CPU Usage: 0%
<debug> nrf_ble_gatt: Requesting to update ATT MTU to 158 bytes on connection 0x0.
<debug> nrf_ble_gatt: Updating data length to 251 on connection 0x0.
<error> nrf_ble_gatt: sd_ble_gap_data_length_update() (request) on connection 0x0 returned NRF_ERROR_RESOURCES.
<error> nrf_ble_gatt: The requested TX/RX packet length is too long by 89/89 octets.
<debug> nrf_ble_gatt: ATT MTU updated to 158 bytes on connection 0x0 (response).
<info> pwr_mgmt: CPU Usage: 0%
<debug> nrf_ble_gatt: Peer on connection 0x0 requested a data length of 123 bytes.
<debug> nrf_ble_gatt: Updating data length to 123 on connection 0x0.
<debug> nrf_ble_gatt: Data length updated to 123 on connection 0x0.
<debug> nrf_ble_gatt: max_rx_octets: 123
<debug> nrf_ble_gatt: max_tx_octets: 123
<debug> nrf_ble_gatt: max_rx_time: 1096
<debug> nrf_ble_gatt: max_tx_time: 1096
<info> app: BLE NUS connected
<info> pwr_mgmt: CPU Usage: 0%
<info> app: strlen: 63
<info> pwr_mgmt: CPU Usage: 43%
<info> app: strlen: 63
<info> pwr_mgmt: CPU Usage: 58%
<info> app: strlen: 63
<info> pwr_mgmt: CPU Usage: 58%
<info> app: strlen: 63
<info> pwr_mgmt: CPU Usage: 57%
<info> app: strlen: 63
<info> pwr_mgmt: CPU Usage: 57%
<info> app: strlen: 63
<info> pwr_mgmt: CPU Usage: 57%
<info> app: strlen: 63
<info> pwr_mgmt: CPU Usage: 57%
<info> app: strlen: 63

    So the stack negotiated a length of 123 and I want to send 63. Still, the problem persists.

  • 0 in reply to Einar Thorsrud

    Hi Einar,

    I was able get back to my original problem. I replicated the issue on an nRF52840-DK. Same phenomenon: CPU usage goes up and stays there for the next reset.

  • 0 in reply to rmakl

    Hi,

    Can you share the code you use to reproduce this on a DK so that I can test on my side?

  • 0 in reply to Einar Thorsrud

    Here is the project files. It resides in "nRF5_SDK_for_Thread_and_Zigbee_v4.1.0_32ce5f8\examples\multiprotocol\ble_thread\"

  • +2 in reply to rmakl

    Hi Roland,

    This issue is not related to NUS. You can see that by modifying your sensor_list_timeout_evt_handler() function to just send dummy data - in that case there is no increase in current consumption.

    The actual problem here is triggered by the sprintf call, which uses the FPU (for doing correct rounding of the float value). However, you have not enabled the workaround for erratum 87. The fix is to enable the workaround by setting NRF_PWR_MGMT_CONFIG_FPU_SUPPORT_ENABLED in sdk_config.h to 1.

    Einar

Reply
  • +2 in reply to rmakl

    Hi Roland,

    This issue is not related to NUS. You can see that by modifying your sensor_list_timeout_evt_handler() function to just send dummy data - in that case there is no increase in current consumption.

    The actual problem here is triggered by the sprintf call, which uses the FPU (for doing correct rounding of the float value). However, you have not enabled the workaround for erratum 87. The fix is to enable the workaround by setting NRF_PWR_MGMT_CONFIG_FPU_SUPPORT_ENABLED in sdk_config.h to 1.

    Einar

Children
Related