Firmware lockup after BLE disconnect while writing to NUS transport

Question

In developing project firmware uses bluetooth shell and one command outputs many lines.

It works fine. Unfortunately, firmware locks up after phone BLE app disconnect in the middle or output. Not every time but it does and requires firmware reboot which is not desirable.

I created example which exhibits the issue using NCS 2.6.1 used by our project. NRF52840dk board is used to build and run example.

Debugger shows that shell_bt_nus thread is stuck on event poll

Kind Regards

shell_ops.c: z_shell_write:shell_pend_on_txdone:k_poll(&event, 1, K_FOREVER);543026.prj.conf

Fullscreen 5822.main.c Download

/*
 * Copyright (c) 2019 Nordic Semiconductor ASA
 *
 * SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
 */

/** @file
 *  @brief Derived from Nordic UART Service (NUS) sample
 */

#include <zephyr/kernel.h>
#include <zephyr/bluetooth/bluetooth.h>
#include <zephyr/bluetooth/uuid.h>
#include <zephyr/bluetooth/gatt.h>
#include <zephyr/bluetooth/hci.h>
#include <bluetooth/services/nus.h>
#include <zephyr/logging/log.h>
#include <shell/shell_bt_nus.h>
#include <stdio.h>

#include <zephyr/shell/shell.h>
#include <zephyr/shell/shell_uart.h>

LOG_MODULE_REGISTER(app);

#define DEVICE_NAME             CONFIG_BT_DEVICE_NAME
#define DEVICE_NAME_LEN	        (sizeof(DEVICE_NAME) - 1)


static struct bt_conn *current_conn=NULL;

static const struct bt_data ad[] = {
	BT_DATA_BYTES(BT_DATA_FLAGS, (BT_LE_AD_GENERAL | BT_LE_AD_NO_BREDR)),
	BT_DATA(BT_DATA_NAME_COMPLETE, DEVICE_NAME, DEVICE_NAME_LEN),
};

static const struct bt_data sd[] = {
	BT_DATA_BYTES(BT_DATA_UUID128_ALL, BT_UUID_NUS_VAL),
};

static void connected(struct bt_conn *conn, uint8_t err)
{
	if (err) {
		LOG_ERR("Connection failed (err %u)", err);
		return;
	}

	LOG_INF("Connected");
	current_conn = bt_conn_ref(conn);
	shell_bt_nus_enable(conn);
}

static void disconnected(struct bt_conn *conn, uint8_t reason)
{
	LOG_INF("Disconnected (reason %u)", reason);
	//set_cancel_cmd();
	shell_bt_nus_disable();
	if (current_conn) {
		bt_conn_unref(current_conn);
		current_conn = NULL;
	}
}

static char *log_addr(struct bt_conn *conn)
{
	static char addr[BT_ADDR_LE_STR_LEN];

	bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));

	return addr;
}

static void __attribute__((unused)) security_changed(struct bt_conn *conn,
						     bt_security_t level,
						     enum bt_security_err err)
{
	char *addr = log_addr(conn);

	if (!err) {
		LOG_INF("Security changed: %s level %u", addr, level);
	} else {
		LOG_INF("Security failed: %s level %u err %d", addr, level,
			err);
	}
}

BT_CONN_CB_DEFINE(conn_callbacks) = {
	.connected    = connected,
	.disconnected = disconnected,
	COND_CODE_1(CONFIG_BT_SMP,
		    (.security_changed = security_changed), ())
};


/* 1000 msec = 1 sec */
#define SLEEP_TIME_MS   10000


int main(void)
{
	int err;

	printk("Starting Bluetooth NUS shell transport example\n");


	err = bt_enable(NULL);
	if (err) {
		LOG_ERR("BLE enable failed (err: %d)", err);
		return 0;
	}

	err = shell_bt_nus_init();
	if (err) {
		LOG_ERR("Failed to initialize BT NUS shell (err: %d)", err);
		return 0;
	}

	err = bt_le_adv_start(BT_LE_ADV_CONN, ad, ARRAY_SIZE(ad), sd,
			      ARRAY_SIZE(sd));
	if (err) {
		LOG_ERR("Advertising failed to start (err %d)", err);
		return 0;
	}

	LOG_INF("Bluetooth ready. Advertising started.");

	int ret=0;
	bool toggle_state = true;

	if (ret < 0) {
		return 0;
	}

	while (1) {
		toggle_state = !toggle_state;
		LOG_INF("Toggle state: %s", toggle_state ? "ON" : "OFF");
		k_msleep(SLEEP_TIME_MS);
	}

	return 0;
}
//--- test shell commands-----
static uint32_t line_cnt = 0;
static int cmd_tsts(const struct shell *sh, size_t argc, char *argv[])
{
	const struct shell * sh_uart = shell_backend_uart_get_ptr();
	shell_fprintf(sh_uart, SHELL_NORMAL,"cmd_tst start\n");
	if ( argc == 1)
	{
		shell_help(sh);
	}
	if ( argc ==2)
	{
		if ( strncmp( argv[1],"info",4) == 0)
		{
			shell_fprintf(sh, SHELL_NORMAL, "INFO: line count = %d\n",line_cnt);
		}
		if ( strncmp( argv[1],"clear",5) == 0)
		{
			line_cnt = 0;
			shell_fprintf(sh, SHELL_NORMAL, "CLEAR: line count = %d\n",line_cnt);
		}
		if ( strncmp( argv[1],"dump",5) == 0)
		{
			for( int i = 0; i < 200; i++)
			{
				line_cnt++;
				if (sh->ctx->state == SHELL_STATE_ACTIVE)
				{ 
					shell_fprintf(sh, SHELL_NORMAL, " line count = %d\n",line_cnt);
				}
				else
				{
					shell_fprintf(sh_uart, SHELL_NORMAL,"cmd_tst lost connection\n");
					break;
				}
			}
		}
	}
	shell_fprintf(sh_uart, SHELL_NORMAL,"cmd_tst stop\n");
	return 0;
}
SHELL_CMD_REGISTER(tst, NULL,
"TEST commands: \r\n"\
	"\t info - return info\r\n"\
	"\t clear - clear info\r\n"\
	"\t dump - dumps lots of messages\r\n", 
	cmd_tsts);