Zephyr crashing when I connect to a device

[DiBosco]

 Vidar Berg has been helping me connect to a device and I am finally able to do that, but as soon as I do, Zephyr crashes.

This is with a lightly modified central_uart project

[00:00:00.024,810] <0x1b>[0m<inf> central_uart: Scan module initialized<0x1b>[0m␍␊

[00:00:00.024,810] <0x1b>[0m<inf> central_uart: NUS Client module initialized<0x1b>[0m␍␊

[00:00:00.029,846] <0x1b>[0m<inf> central_uart: Scanning successfully started<0x1b>[0m␍␊

[00:00:00.093,719] <0x1b>[0m<inf> central_uart: Filters matched. Address: E8:A0:DB:24:21:62 (random) connectable: 1<0x1b>[0m␍␊

[00:00:00.289,886] <0x1b>[0m<inf> central_uart: Connected: E8:A0:DB:24:21:62 (random)<0x1b>[0m␍␊

[00:00:00.290,039] <0x1b>[1;33m<wrn> central_uart: Failed to set security: -12<0x1b>[0m␍␊

[00:00:00.290,100] <0x1b>[1;31m<err> central_uart: Stop LE scan failed (err 0)<0x1b>[0m␍␊

[00:00:00.441,497] <0x1b>[0m<inf> central_uart: MTU exchange done<0x1b>[0m␍␊

ASSERTION FAIL [conn] @ WEST_TOPDIR/zephyr/subsys/bluetooth/host/gatt.c:5433␍␊

⇥ invalid parameters␍␊

␍␊

[00:00:01.791,351] <0x1b>[0m<inf> central_uart: Service discovery completed<0x1b>[0m␍␊

[00:00:01.800,994] <0x1b>[1;31m<err> os: r0/a1: 0x00000004 r1/a2: 0x00001539 r2/a3: 0x20000b60<0x1b>[0m␍␊

[00:00:01.800,994] <0x1b>[1;31m<err> os: r3/a4: 0x00000004 r12/ip: 0x00000000 r14/lr: 0x000217df<0x1b>[0m␍␊

[00:00:01.801,025] <0x1b>[1;31m<err> os: xpsr: 0x21000000<0x1b>[0m␍␊

[00:00:01.801,025] <0x1b>[1;31m<err> os: Faulting instruction address (r15/pc): 0x00031072<0x1b>[0m␍␊

[00:00:01.801,086] <0x1b>[1;31m<err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0<0x1b>[0m␍␊

[00:00:01.801,116] <0x1b>[1;31m<err> os: Current thread: 0x20002568 (BT RX WQ)<0x1b>[0m␍␊

[00:00:01.869,415] <0x1b>[1;31m<err> os: Halting system<0x1b>[0m␍␊

The program crashes here:

 

return snprintk(str, len, "%02X:%02X:%02X:%02X:%02X:%02X (%s)",

addr->a.val[5], addr->a.val[4], addr->a.val[3],

addr->a.val[2], addr->a.val[1], addr->a.val[0], type);

Which is in

addr.h (sic) Quite what code is doing in a header file is beyond me.

The prototype for the function is this:

int bt_addr_le_to_str(const bt_addr_le_t *addr, char *str, size_t len);

The values passed look reasonable to me.

addr->a.val[0]-[5] have the correct MAC address in it

str has (in decimal) 23 0 ... in it so that looks like it's just got a single character and anyway,

it shouldn't make a difference because, surely, that's being written into.

len = 30

type ends up with "random" in it.

I am assuming

snprintk is based on

snprint and so shouldn't copy more than len bytes anyway.

The string being used is that is passed into bt_addr_le_to_str is:

char addr[BT_ADDR_LE_STR_LEN];

and BT_ADDR_LE_STR_LEN is set to 30 so that all stacks up nicely.

Can anyone give me some pointers as to what might be wrong here?

BTW  Vidar Berg that little project you sent me does not crash like this, but I can't

see where you set up the characteristics for that project, there is no reference to

BT_GATT_SERVICE_DEFINE anywhere in it. I would happily just mod that if I could work out how you've set up

its service and characteristics.

Thanks

[Vidar Berg]

Hello,

ASSERTION FAIL [conn] @ WEST_TOPDIR/zephyr/subsys/bluetooth/host/gatt.c:5433

This error message shows that an assertion is raised in gatt.c at this line: https://github.com/nrfconnect/sdk-zephyr/blob/0bc3393fb112ec80ebeab48cd023d69b1e9db757/subsys/bluetooth/host/gatt.c#L5433 which suggests that the 'conn' pointer passed to your bt_gatt_subscribe() call is set to NULL. 

hat little project you sent me does not crash like this, but I can't

see where you set up the characteristics for that project, there is no reference to

I copied the NUS service and NUS client source files and placed them in the project's source directory (I also renamed every occurrence of 'nus' to 'custom').

Best regards,

Vidar

[DiBosco]

Morning,

I did look with the debugger at that pointer and that's not the issue.

The crash doesn't come until snprintk in bt_addr_le_to_str

and as I say, in the first post, The values in passed to:

return snprintk(str, len, "%02X:%02X:%02X:%02X:%02X:%02X (%s)",

addr->a.val[5], addr->a.val[4], addr->a.val[3],

addr->a.val[2], addr->a.val[1], addr->a.val[0], type);

Look fine:



This smacks more of a stack overflow to me,

but I've massively increased the main stack size in prj.conf

to no or little avail.

The message on crash changes slightly:

[00:00:07.404,510] <0x1b>[1;31m<err> os: Fault during interrupt handling␊

<0x1b>[0m␍␊

[00:00:07.404,571] <0x1b>[1;31m<err> os: Current thread:

0x20002568 (BT RX WQ)<0x1b>[0m␍␊

This looks like it;s some sort bluetooth receive issue? However, all I'm doing is

connecting, no actual data is being sent as yet.

On the subject of your code, it's not the peripheral_uart I'm trying, it's the

central_uart which doesn't have those definitions in it. .

 

[DiBosco]

OK, a little more info and more questions:

Firstly - and I'm not sure this actually matters in terms of it functioning. This second line must be wrong:

err = bt_scan_stop();

if ((NO_ERROR == err) && (err != -EALREADY))

{

LOG_ERR("Stop LE scan failed (err %d)", err);

}

This line was originally the mind bending:

if ((!err) && (err != -EALREADY))

Even when written out to make it much more understandable where

NO_ERROR is defined as 0 rather than a magic number that is
littered throughout all this code.

This seems like a mad line of code. If err is equal to 0
it can't be anything else.

However, as it's just printing out a line of debug code I
suspect it doesn't actually matter.

What doesn't seem to be getting called though is this:

discovery_complete

This is used in this:

struct bt_gatt_dm_cb discovery_cb

Which in turn is filled out, I think, in

gatt_discover

But

gatt_discover never gets called from here:

err = bt_conn_set_security(conn, BT_SECURITY_L1);

if (NO_ERROR != err) // was if (err), changed for clarity

{

LOG_WRN("Failed to set security: %d", err);

gatt_discover(conn);

}

Surely gatt_discover should be called if err *is* equal

to 0 which is, again, defined as NO_ERROR for clarity.

Oh, also I changed bt_conn_set_security to:

err = bt_conn_set_security(conn, BT_SECURITY_L1);

As we're not using security on our unit and it was giving
me an error when it was set to L2. Does that sound right?

gatt_discover is also called in:

security_changed, but security_changed never gets called
(I don't know what this is for).

[Vidar Berg]

I made some edits to the GATT client implementation I posted earlier to also enable notifications for the second characteristic. Please try it with this.

Fullscreen custom_client.c Download

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

#include <zephyr/bluetooth/conn.h>
#include <zephyr/bluetooth/uuid.h>
#include <zephyr/bluetooth/gatt.h>

#include "custom_client.h"

#include <zephyr/logging/log.h>
LOG_MODULE_REGISTER(custom_c, CONFIG_BT_CUSTOM_CLIENT_LOG_LEVEL);

enum {
	CUSTOM_C_INITIALIZED,
	CUSTOM_C_TX_NOTIF_ENABLED,
	CUSTOM_C_RX_NOTIF_ENABLED,
	CUSTOM_C_RX_WRITE_PENDING
};

static uint8_t on_received_tx(struct bt_conn *conn,
			struct bt_gatt_subscribe_params *params,
			const void *data, uint16_t length)
{
	struct bt_custom_client *custom;

	/* Retrieve CUSTOM Client module context. */
	custom = CONTAINER_OF(params, struct bt_custom_client, tx_notif_params);

	if (!data) {
		LOG_DBG("[UNSUBSCRIBED]");
		params->value_handle = 0;
		atomic_clear_bit(&custom->state, CUSTOM_C_TX_NOTIF_ENABLED);
		if (custom->cb.unsubscribed) {
			custom->cb.unsubscribed(custom);
		}
		return BT_GATT_ITER_STOP;
	}

	LOG_DBG("[NOTIFICATION] data %p length %u", data, length);
	if (custom->cb.received_tx) {
		return custom->cb.received_tx(custom, data, length);
	}

	return BT_GATT_ITER_CONTINUE;
}

static uint8_t on_received_rx(struct bt_conn *conn,
			struct bt_gatt_subscribe_params *params,
			const void *data, uint16_t length)
{
	struct bt_custom_client *custom;

	/* Retrieve CUSTOM Client module context. */
	custom = CONTAINER_OF(params, struct bt_custom_client, rx_notif_params);

	if (!data) {
		LOG_DBG("[UNSUBSCRIBED]");
		params->value_handle = 0;
		atomic_clear_bit(&custom->state, CUSTOM_C_RX_NOTIF_ENABLED);
		if (custom->cb.unsubscribed) {
			custom->cb.unsubscribed(custom);
		}
		return BT_GATT_ITER_STOP;
	}

	LOG_DBG("[NOTIFICATION] data %p length %u", data, length);
	if (custom->cb.received_rx) {
		return custom->cb.received_rx(custom, data, length);
	}

	return BT_GATT_ITER_CONTINUE;
}

static void on_sent(struct bt_conn *conn, uint8_t err,
		    struct bt_gatt_write_params *params)
{
	struct bt_custom_client *custom_c;
	const void *data;
	uint16_t length;

	/* Retrieve CUSTOM Client module context. */
	custom_c = CONTAINER_OF(params, struct bt_custom_client, tx_write_params);

	/* Make a copy of volatile data that is required by the callback. */
	data = params->data;
	length = params->length;

	atomic_clear_bit(&custom_c->state, CUSTOM_C_RX_WRITE_PENDING);
	if (custom_c->cb.sent) {
		custom_c->cb.sent(custom_c, err, data, length);
	}
}

int bt_custom_client_init(struct bt_custom_client *custom_c,
		       const struct bt_custom_client_init_param *custom_c_init)
{
	if (!custom_c || !custom_c_init) {
		return -EINVAL;
	}

	if (atomic_test_and_set_bit(&custom_c->state, CUSTOM_C_INITIALIZED)) {
		return -EALREADY;
	}

	memcpy(&custom_c->cb, &custom_c_init->cb, sizeof(custom_c->cb));

	return 0;
}

int bt_custom_client_send(struct bt_custom_client *custom_c, const uint8_t *data,
		       uint16_t len)
{
	int err;

	if (!custom_c->conn) {
		return -ENOTCONN;
	}

	if (atomic_test_and_set_bit(&custom_c->state, CUSTOM_C_RX_WRITE_PENDING)) {
		return -EALREADY;
	}

	custom_c->tx_write_params.func = on_sent;
	custom_c->tx_write_params.handle = custom_c->handles.rx;
	custom_c->tx_write_params.offset = 0;
	custom_c->tx_write_params.data = data;
	custom_c->tx_write_params.length = len;

	err = bt_gatt_write(custom_c->conn, &custom_c->tx_write_params);
	if (err) {
		atomic_clear_bit(&custom_c->state, CUSTOM_C_RX_WRITE_PENDING);
	}

	return err;
}

int bt_custom_handles_assign(struct bt_gatt_dm *dm,
			  struct bt_custom_client *custom_c)
{
	const struct bt_gatt_dm_attr *gatt_service_attr =
			bt_gatt_dm_service_get(dm);
	const struct bt_gatt_service_val *gatt_service =
			bt_gatt_dm_attr_service_val(gatt_service_attr);
	const struct bt_gatt_dm_attr *gatt_chrc;
	const struct bt_gatt_dm_attr *gatt_desc;

	if (bt_uuid_cmp(gatt_service->uuid, BT_UUID_CUSTOM_SERVICE)) {
		return -ENOTSUP;
	}
	LOG_DBG("Getting handles from CUSTOM service.");
	memset(&custom_c->handles, 0xFF, sizeof(custom_c->handles));

	/* CUSTOM TX Characteristic */
	gatt_chrc = bt_gatt_dm_char_by_uuid(dm, BT_UUID_CUSTOM_TX);
	if (!gatt_chrc) {
		LOG_ERR("Missing CUSTOM TX characteristic.");
		return -EINVAL;
	}
	/* CUSTOM TX */
	gatt_desc = bt_gatt_dm_desc_by_uuid(dm, gatt_chrc, BT_UUID_CUSTOM_TX);
	if (!gatt_desc) {
		LOG_ERR("Missing CUSTOM TX value descriptor in characteristic.");
		return -EINVAL;
	}
	LOG_DBG("Found handle for CUSTOM TX characteristic.");
	custom_c->handles.tx = gatt_desc->handle;
	/* CUSTOM TX CCC */
	gatt_desc = bt_gatt_dm_desc_by_uuid(dm, gatt_chrc, BT_UUID_GATT_CCC);
	if (!gatt_desc) {
		LOG_ERR("Missing CUSTOM TX CCC in characteristic.");
		return -EINVAL;
	}
	LOG_DBG("Found handle for CCC of CUSTOM TX characteristic.");
	custom_c->handles.tx_ccc = gatt_desc->handle;

	/* CUSTOM RX Characteristic */
	gatt_chrc = bt_gatt_dm_char_by_uuid(dm, BT_UUID_CUSTOM_RX);
	if (!gatt_chrc) {
		LOG_ERR("Missing CUSTOM RX characteristic.");
		return -EINVAL;
	}
	/* CUSTOM RX */
	gatt_desc = bt_gatt_dm_desc_by_uuid(dm, gatt_chrc, BT_UUID_CUSTOM_RX);
	if (!gatt_desc) {
		LOG_ERR("Missing CUSTOM RX value descriptor in characteristic.");
		return -EINVAL;
	}
	LOG_DBG("Found handle for CUSTOM RX characteristic.");
	custom_c->handles.rx = gatt_desc->handle;

	/* CUSTOM RX CCC */
	gatt_desc = bt_gatt_dm_desc_by_uuid(dm, gatt_chrc, BT_UUID_GATT_CCC);
	if (!gatt_desc) {
		LOG_ERR("Missing CUSTOM TX CCC in characteristic.");
		return -EINVAL;
	}

	LOG_DBG("Found handle for CCC of CUSTOM RX characteristic.");
	custom_c->handles.rx_ccc = gatt_desc->handle;

	/* Assign connection instance. */
	custom_c->conn = bt_gatt_dm_conn_get(dm);
	return 0;
}

int bt_custom_subscribe_tx_receive(struct bt_custom_client *custom_c)
{
	int err;

	if (atomic_test_and_set_bit(&custom_c->state, CUSTOM_C_TX_NOTIF_ENABLED)) {
		return -EALREADY;
	}

	custom_c->tx_notif_params.notify = on_received_tx;
	custom_c->tx_notif_params.value = BT_GATT_CCC_NOTIFY;
	custom_c->tx_notif_params.value_handle = custom_c->handles.tx;
	custom_c->tx_notif_params.ccc_handle = custom_c->handles.tx_ccc;
	atomic_set_bit(custom_c->tx_notif_params.flags,
		       BT_GATT_SUBSCRIBE_FLAG_VOLATILE);

	err = bt_gatt_subscribe(custom_c->conn, &custom_c->tx_notif_params);
	if (err) {
		LOG_ERR("Subscribe failed (err %d)", err);
		atomic_clear_bit(&custom_c->state, CUSTOM_C_TX_NOTIF_ENABLED);
	} else {
		LOG_DBG("[SUBSCRIBED]");
	}

	return err;
}

int bt_custom_subscribe_rx_receive(struct bt_custom_client *custom_c)
{
	int err;

	custom_c->rx_notif_params.notify = on_received_rx;
	custom_c->rx_notif_params.value = BT_GATT_CCC_NOTIFY;
	custom_c->rx_notif_params.value_handle = custom_c->handles.rx;
	custom_c->rx_notif_params.ccc_handle = custom_c->handles.rx_ccc;


	err = bt_gatt_subscribe(custom_c->conn, &custom_c->rx_notif_params);
	if (err) {
		LOG_ERR("Subscribe failed (err %d)", err);
		atomic_clear_bit(&custom_c->state, CUSTOM_C_TX_NOTIF_ENABLED);
	} else {
		LOG_DBG("[SUBSCRIBED]");
	}

	return err;
}

custom_client.h

Fullscreen 3146.diff.diff Download

diff --git a/prj.conf b/prj.conf
index eacd454..e598756 100644
--- a/prj.conf
+++ b/prj.conf
@@ -41,4 +41,6 @@ CONFIG_LOG_PRINTK=n
 CONFIG_ASSERT=y
 
 CONFIG_NCS_BOOT_BANNER=n
-CONFIG_BOOT_BANNER=n
\ No newline at end of file
+CONFIG_BOOT_BANNER=n
+
+CONFIG_BT_CUSTOM_CLIENT_LOG_LEVEL_DBG=y
\ No newline at end of file
diff --git a/src/bt_client/custom_client.c b/src/bt_client/custom_client.c
index a7dffde..f9cbe02 100644
--- a/src/bt_client/custom_client.c
+++ b/src/bt_client/custom_client.c
@@ -16,10 +16,11 @@ LOG_MODULE_REGISTER(custom_c, CONFIG_BT_CUSTOM_CLIENT_LOG_LEVEL);
 enum {
 	CUSTOM_C_INITIALIZED,
 	CUSTOM_C_TX_NOTIF_ENABLED,
+	CUSTOM_C_RX_NOTIF_ENABLED,
 	CUSTOM_C_RX_WRITE_PENDING
 };
 
-static uint8_t on_received(struct bt_conn *conn,
+static uint8_t on_received_tx(struct bt_conn *conn,
 			struct bt_gatt_subscribe_params *params,
 			const void *data, uint16_t length)
 {
@@ -39,8 +40,35 @@ static uint8_t on_received(struct bt_conn *conn,
 	}
 
 	LOG_DBG("[NOTIFICATION] data %p length %u", data, length);
-	if (custom->cb.received) {
-		return custom->cb.received(custom, data, length);
+	if (custom->cb.received_tx) {
+		return custom->cb.received_tx(custom, data, length);
+	}
+
+	return BT_GATT_ITER_CONTINUE;
+}
+
+static uint8_t on_received_rx(struct bt_conn *conn,
+			struct bt_gatt_subscribe_params *params,
+			const void *data, uint16_t length)
+{
+	struct bt_custom_client *custom;
+
+	/* Retrieve CUSTOM Client module context. */
+	custom = CONTAINER_OF(params, struct bt_custom_client, rx_notif_params);
+
+	if (!data) {
+		LOG_DBG("[UNSUBSCRIBED]");
+		params->value_handle = 0;
+		atomic_clear_bit(&custom->state, CUSTOM_C_RX_NOTIF_ENABLED);
+		if (custom->cb.unsubscribed) {
+			custom->cb.unsubscribed(custom);
+		}
+		return BT_GATT_ITER_STOP;
+	}
+
+	LOG_DBG("[NOTIFICATION] data %p length %u", data, length);
+	if (custom->cb.received_rx) {
+		return custom->cb.received_rx(custom, data, length);
 	}
 
 	return BT_GATT_ITER_CONTINUE;
@@ -54,7 +82,7 @@ static void on_sent(struct bt_conn *conn, uint8_t err,
 	uint16_t length;
 
 	/* Retrieve CUSTOM Client module context. */
-	custom_c = CONTAINER_OF(params, struct bt_custom_client, rx_write_params);
+	custom_c = CONTAINER_OF(params, struct bt_custom_client, tx_write_params);
 
 	/* Make a copy of volatile data that is required by the callback. */
 	data = params->data;
@@ -95,13 +123,13 @@ int bt_custom_client_send(struct bt_custom_client *custom_c, const uint8_t *data
 		return -EALREADY;
 	}
 
-	custom_c->rx_write_params.func = on_sent;
-	custom_c->rx_write_params.handle = custom_c->handles.rx;
-	custom_c->rx_write_params.offset = 0;
-	custom_c->rx_write_params.data = data;
-	custom_c->rx_write_params.length = len;
+	custom_c->tx_write_params.func = on_sent;
+	custom_c->tx_write_params.handle = custom_c->handles.rx;
+	custom_c->tx_write_params.offset = 0;
+	custom_c->tx_write_params.data = data;
+	custom_c->tx_write_params.length = len;
 
-	err = bt_gatt_write(custom_c->conn, &custom_c->rx_write_params);
+	err = bt_gatt_write(custom_c->conn, &custom_c->tx_write_params);
 	if (err) {
 		atomic_clear_bit(&custom_c->state, CUSTOM_C_RX_WRITE_PENDING);
 	}
@@ -163,12 +191,22 @@ int bt_custom_handles_assign(struct bt_gatt_dm *dm,
 	LOG_DBG("Found handle for CUSTOM RX characteristic.");
 	custom_c->handles.rx = gatt_desc->handle;
 
+	/* CUSTOM RX CCC */
+	gatt_desc = bt_gatt_dm_desc_by_uuid(dm, gatt_chrc, BT_UUID_GATT_CCC);
+	if (!gatt_desc) {
+		LOG_ERR("Missing CUSTOM TX CCC in characteristic.");
+		return -EINVAL;
+	}
+
+	LOG_DBG("Found handle for CCC of CUSTOM RX characteristic.");
+	custom_c->handles.rx_ccc = gatt_desc->handle;
+
 	/* Assign connection instance. */
 	custom_c->conn = bt_gatt_dm_conn_get(dm);
 	return 0;
 }
 
-int bt_custom_subscribe_receive(struct bt_custom_client *custom_c)
+int bt_custom_subscribe_tx_receive(struct bt_custom_client *custom_c)
 {
 	int err;
 
@@ -176,7 +214,7 @@ int bt_custom_subscribe_receive(struct bt_custom_client *custom_c)
 		return -EALREADY;
 	}
 
-	custom_c->tx_notif_params.notify = on_received;
+	custom_c->tx_notif_params.notify = on_received_tx;
 	custom_c->tx_notif_params.value = BT_GATT_CCC_NOTIFY;
 	custom_c->tx_notif_params.value_handle = custom_c->handles.tx;
 	custom_c->tx_notif_params.ccc_handle = custom_c->handles.tx_ccc;
@@ -193,3 +231,24 @@ int bt_custom_subscribe_receive(struct bt_custom_client *custom_c)
 
 	return err;
 }
+
+int bt_custom_subscribe_rx_receive(struct bt_custom_client *custom_c)
+{
+	int err;
+
+	custom_c->rx_notif_params.notify = on_received_rx;
+	custom_c->rx_notif_params.value = BT_GATT_CCC_NOTIFY;
+	custom_c->rx_notif_params.value_handle = custom_c->handles.rx;
+	custom_c->rx_notif_params.ccc_handle = custom_c->handles.rx_ccc;
+
+
+	err = bt_gatt_subscribe(custom_c->conn, &custom_c->rx_notif_params);
+	if (err) {
+		LOG_ERR("Subscribe failed (err %d)", err);
+		atomic_clear_bit(&custom_c->state, CUSTOM_C_TX_NOTIF_ENABLED);
+	} else {
+		LOG_DBG("[SUBSCRIBED]");
+	}
+
+	return err;
+}
\ No newline at end of file
diff --git a/src/bt_client/custom_client.h b/src/bt_client/custom_client.h
index 303ddf8..062a296 100644
--- a/src/bt_client/custom_client.h
+++ b/src/bt_client/custom_client.h
@@ -48,6 +48,11 @@ struct bt_custom_client_handles {
          */
 	uint16_t rx;
 
+    /** Handle of the CCC descriptor of the CUSTOM RX characteristic,
+	 *  as provided by a discovery.
+     */
+	uint16_t rx_ccc;
+
         /** Handle of the CUSTOM TX characteristic, as provided by
 	 *  a discovery.
          */
@@ -75,7 +80,9 @@ struct bt_custom_client_cb {
 	 * @retval BT_GATT_ITER_CONTINUE To keep notifications enabled.
 	 * @retval BT_GATT_ITER_STOP To disable notifications.
 	 */
-	uint8_t (*received)(struct bt_custom_client *custom, const uint8_t *data, uint16_t len);
+	uint8_t (*received_tx)(struct bt_custom_client *custom, const uint8_t *data, uint16_t len);
+
+	uint8_t (*received_rx)(struct bt_custom_client *custom, const uint8_t *data, uint16_t len);
 
 	/** @brief Data sent callback.
 	 *
@@ -114,8 +121,11 @@ struct bt_custom_client {
         /** GATT subscribe parameters for CUSTOM TX Characteristic. */
 	struct bt_gatt_subscribe_params tx_notif_params;
 
+        /** GATT subscribe parameters for CUSTOM RX Characteristic. */
+	struct bt_gatt_subscribe_params rx_notif_params;
+
         /** GATT write parameters for CUSTOM RX Characteristic. */
-	struct bt_gatt_write_params rx_write_params;
+	struct bt_gatt_write_params tx_write_params;
 
         /** Application callbacks. */
 	struct bt_custom_client_cb cb;
@@ -189,7 +199,9 @@ int bt_custom_handles_assign(struct bt_gatt_dm *dm,
  * @retval 0 If the operation was successful.
  *           Otherwise, a negative error code is returned.
  */
-int bt_custom_subscribe_receive(struct bt_custom_client *custom);
+int bt_custom_subscribe_tx_receive(struct bt_custom_client *custom);
+
+int bt_custom_subscribe_rx_receive(struct bt_custom_client *custom);
 
 #ifdef __cplusplus
 }
diff --git a/src/main.c b/src/main.c
index dcfc7cf..4c65942 100644
--- a/src/main.c
+++ b/src/main.c
@@ -75,7 +75,7 @@ static void ble_data_sent(struct bt_custom_client *custom, uint8_t err,
 	}
 }
 
-static uint8_t ble_data_received(struct bt_custom_client *custom,
+static uint8_t ble_data_received_tx(struct bt_custom_client *custom,
 						const uint8_t *data, uint16_t len)
 {
 	ARG_UNUSED(custom);
@@ -120,6 +120,16 @@ static uint8_t ble_data_received(struct bt_custom_client *custom,
 	return BT_GATT_ITER_CONTINUE;
 }
 
+static uint8_t ble_data_received_rx(struct bt_custom_client *custom,
+						const uint8_t *data, uint16_t len)
+{
+	ARG_UNUSED(custom);
+
+	LOG_INF("Received data from RX characteristic");
+
+	return BT_GATT_ITER_CONTINUE;
+}
+
 static void uart_cb(const struct device *dev, struct uart_event *evt, void *user_data)
 {
 	ARG_UNUSED(dev);
@@ -294,7 +304,8 @@ static void discovery_complete(struct bt_gatt_dm *dm,
 	bt_gatt_dm_data_print(dm);
 
 	bt_custom_handles_assign(dm, custom);
-	bt_custom_subscribe_receive(custom);
+	bt_custom_subscribe_tx_receive(custom);
+	bt_custom_subscribe_rx_receive(custom);
 
 	bt_gatt_dm_data_release(dm);
 }
@@ -380,15 +391,10 @@ static void connected(struct bt_conn *conn, uint8_t conn_err)
 		LOG_WRN("MTU exchange failed (err %d)", err);
 	}
 
-	err = bt_conn_set_security(conn, BT_SECURITY_L2);
-	if (err) {
-		LOG_WRN("Failed to set security: %d", err);
-
-		gatt_discover(conn);
-	}
-
+	gatt_discover(conn);
+	
 	err = bt_scan_stop();
-	if ((!err) && (err != -EALREADY)) {
+	if ((err) && (err != -EALREADY)) {
 		LOG_ERR("Stop LE scan failed (err %d)", err);
 	}
 }
@@ -467,7 +473,8 @@ static int custom_client_init(void)
 	int err;
 	struct bt_custom_client_init_param init = {
 		.cb = {
-			.received = ble_data_received,
+			.received_tx = ble_data_received_tx,
+			.received_rx = ble_data_received_rx,
 			.sent = ble_data_sent,
 		}
 	};
@@ -501,19 +508,17 @@ static int scan_init(void)
 {
 	int err;
 	struct bt_scan_init_param scan_init = {
-		.connect_if_match = 0,
+		.connect_if_match = 1,
 	};
 
 	bt_scan_init(&scan_init);
 	bt_scan_cb_register(&scan_cb);
 
-	//err = bt_scan_filter_add(BT_SCAN_FILTER_TYPE_UUID, BT_UUID_CUSTOM_SERVICE);
-	//if (err) {
-	//	LOG_ERR("Scanning filters cannot be set (err %d)", err);
-	//	return err;
-	//}
-
-
+	err = bt_scan_filter_add(BT_SCAN_FILTER_TYPE_UUID, BT_UUID_CUSTOM_SERVICE);
+	if (err) {
+		LOG_ERR("Scanning filters cannot be set (err %d)", err);
+		return err;
+	}
 
 	bt_addr_le_t addr = {
 		.type = BT_ADDR_LE_RANDOM,
@@ -526,7 +531,7 @@ static int scan_init(void)
 		return err;
 	}
 
-	err = bt_scan_filter_enable(BT_SCAN_ADDR_FILTER, false);
+	err = bt_scan_filter_enable(BT_SCAN_UUID_FILTER, false);
 	if (err) {
 		LOG_ERR("Filters cannot be turned on (err %d)", err);
 		return err;

This change is also required in main.c:

@@ -294,7 +304,8 @@ static void discovery_complete(struct bt_gatt_dm *dm,
 	bt_gatt_dm_data_print(dm);
 
 	bt_custom_handles_assign(dm, custom);
-	bt_custom_subscribe_receive(custom);
+	bt_custom_subscribe_tx_receive(custom);
+	bt_custom_subscribe_rx_receive(custom);
 
 	bt_gatt_dm_data_release(dm);
 }

DiBosco said:

if ((!err) && (err != -EALREADY))

I assume the developer intended to write if ((err) && (err != -EALREADY)) so the error message would be printed for any error except -EALREADY. However, I don't see any obvious reasons for ignoring the EALREADY error in this sample. There is no side effect to this as only the error message is printed, which I assume is why it has not been caught by our tests. Will report this internally.

This is how I would have expected it to be written:

	err = bt_scan_stop();
	if (err) {
		LOG_ERR("Stop LE scan failed (err %d)", err);
	}

The use of 0 to indicate success is an established convention in C, and is not limited to Zephyr or the linux kernel. But I see your point. defining a symbol such as NO_ERROR could help improve the code readability. In the old SDK we had the NRF_SUCCESS symbol that was defined as '0'.

DiBosco said:

err = bt_conn_set_security(conn, BT_SECURITY_L1);

As we're not using security on our unit and it was giving
me an error when it was set to L2. Does that sound right?

Since your peripheral doesn't implement BLE security, you can remove this line and call gatt_discover() unconditionally in your connected callback.

[DiBosco]

OK, that's crashing again now:

[00:00:00.013,366] <0x1b>[0m<inf> bt_hci_core: No ID address. App must call settings_load()<0x1b>[0m␍␊

[00:00:00.013,397] <0x1b>[0m<inf> central_uart: Bluetooth initialized<0x1b>[0m␍␊

[00:00:00.014,373] <0x1b>[0m<inf> bt_hci_core: Identity: D9:AD:8D:A9:1A:A2 (random)<0x1b>[0m␍␊

[00:00:00.014,404] <0x1b>[0m<inf> bt_hci_core: HCI: version 6.0 (0x0e) revision 0x104e, manufacturer 0x0059<0x1b>[0m␍␊

[00:00:00.014,434] <0x1b>[0m<inf> bt_hci_core: LMP: version 6.0 (0x0e) subver 0x104e<0x1b>[0m␍␊

[00:00:00.015,747] <0x1b>[1;31m<err> os: ***** USAGE FAULT *****<0x1b>[0m␍␊

[00:00:00.015,747] <0x1b>[1;31m<err> os: Unaligned memory access<0x1b>[0m␍␊

[00:00:00.015,777] <0x1b>[1;31m<err> os: r0/a1: 0x20003800 r1/a2: 0x00000000 r2/a3: 0x00000001<0x1b>[0m␍␊

[00:00:00.015,777] <0x1b>[1;31m<err> os: r3/a4: 0x00038207 r12/ip: 0x00038207 r14/lr: 0x00014bc5<0x1b>[0m␍␊

[00:00:00.015,808] <0x1b>[1;31m<err> os: xpsr: 0x61000000<0x1b>[0m␍␊

[00:00:00.015,808] <0x1b>[1;31m<err> os: Faulting instruction address (r15/pc): 0x00014bd6<0x1b>[0m␍␊

[00:00:00.015,838] <0x1b>[1;31m<err> os: >>> ZEPHYR FATAL ERROR 31: Unknown error on CPU 0<0x1b>[0m␍␊

[00:00:00.015,899] <0x1b>[1;31m<err> os: Current thread: 0x200032c0 (main)<0x1b>[0m␍␊

[00:00:01.547,698] <0x1b>[1;31m<err> os: Halting system<0x1b>[0m␍␊

I can only assume that when modifying the code to allow for this new subscription I've messed something up.

 

Vidar Berg said:

The use of 0 to indicate success is an established convention in C, and is not limited to Zephyr or the linux kernel. But I see your point. defining a symbol such as NO_ERROR could help improve the code readability. In the old SDK we had the NRF_SUCCESS symbol that was defined as '0'.

I do, of course, realise this and I also know that coding style varies massively from person to person. I do appreciate that some people even like K&R style indentation.

I've never liked this

if (whatevs)

type of thing, right from when I started learning C in the 90s it always made me baulk. IMHO code should be as easy as possible to read.

Having done a medical job where they were incredibly strict about stuff like this, as well as things like never using magic numbers it really teaches you how valuable it is to not take short cuts, not to ever have ifs without ==, not to call functions with a call to a function, not use use things like the ternary operator and so on.

I believe some of how C was originally invented was to mitigate for the fact that space to store source code was at a premium, but those days are long gone. Disk space is plentiful and cheap and there's no reason not to be verbose in the interest of clarity.   Especially when you're providing code for others to read. It especially helps when debugging and single stepping through code.

I'll see if I can go through this code by update setting breakpoints and trying to work out where it crashes, in the meantime if there's anything you can thing of to track this down that would be great. I can't pretend to really follow exactly what's going on with these changes, let alone how the system works as whole, I get partway down one of these deep callback/macro/structure in a structure rabbit holes and soon forget where I was up to or what I was trying to do.

Vidar Berg said:

Since your peripheral doesn't implement BLE security, you can remove this line and call gatt_discover() unconditionally in your connected callback.

OK, cool, thanks!

Thanks again for all the help, it is greatly appreciated.

[DiBosco]

Actually, one more thing that might help me.

Those debug messages that are turned on by having:

CONFIG_LOG_BACKEND_UART=y

In the conf file are very useful, but no good when I'm actually
trying to ship traffic through the BLE "UART". Could I route

it through to a different UART, preferably one of the

virtual com ports that are on the debug USB interface?

I do see that I have

/dev/ttyACMx where x is couple of a numbers per dev kit.

Would be great to have one of those take the traffic and send it to Cutecom to see what's going on at the same time I'm trying to use the BLE "UART".

[Vidar Berg]

DiBosco said:

I can only assume that when modifying the code to allow for this new subscription I've messed something up.

I’m not sure what could have triggered the unaligned memory access. The first thing I would do is look up the faulting instruction address to see which line of code it maps to. You can do this either by using arm-zephyr-eabi-addr2line or by placing a breakpoint at the address.

With addr2line:

1. Open a terminal in Vs code with the toolchain env set:

2. Enter the following command from the "nRF connect" terminal

In my case:

DiBosco said:

Would be great to have one of those take the traffic and send it to Cutecom to see what's going on at the same time I'm trying to use the BLE "UART"

Unfortunately, the second COM port on the nRF52840 DK is not connected to the nRF chip on this board. Otherwise, you could have created a board overlay to direct logs to the second UARTE instance.

DiBosco said:

I do, of course, realise this and I also know that coding style varies massively from person to person. I do appreciate that some people even like K&R style indentation.

I don’t have strong opinions on this to be honest, but I think it makes sense for us to follow the same style as Zephyr for consistency, even though there are always things that could be improved.

[DiBosco]

I've solved the crashing issue, that trick worked. 

Am currently getting

#define ENOTCONN 128 /* Socket is not connected */
Error when I try to write to this:

err = bt_custom_client_send(&custom_client, data_ptr, len);
Even though, the system's telling me it's connected to the custom unit.

Vidar Berg said:

Unfortunately, the second COM port on the nRF52840 DK is not connected to the nRF chip on this board. Otherwise, you could have created a board overlay to direct logs to the second UARTE instance.

I don't understand what you're saying here.

First question is:

Assuming you have more than one UART, can you route the

LOG_WRN & LOG_ERR

traffic to that other UART? If so, how. How and where do you

specify *which* UART

is being used for the debug information?

Also, I assume you can change between spitting out

LOG_ERR and LOG_WRN and both? If so, how?

Second question

Assuming the above is possible:

a. This second UART: what do you mean it's not connected to the nrf chip? Surely the second UART is a peripheral IN the nrf? Also, I thought this was a funky chip where you could connect any pin to any peripheral? So as long as the pins are accessible on the SIL headers I can connected up an FTDI  3V3 cable to the second UART just as I am to the first to get UART traffic in and out.

b. There are clearly some virtual com ports on this DK, when the board is powered up via the USB  connection to the board, I get:

crw-rw-rw- 1 root dialout 166, 0 Dec  4 19:50 /dev/ttyACM0
crw-rw-rw- 1 root dialout 166, 1 Dec  4 19:50 /dev/ttyACM1


Now, I know that the debug information comes out of this because at one point I somehow managed to open some sort of terminal in VSC and when

CONFIG_LOG_BACKEND_UART=y

Was in prj.conf

I got the same serial info into VSC as I currently get into Cutecom.

So is it not possible to use that VCP in Cutecom

as the BACKEND UART? This would be the easiest and best way to

do it.

Just in case it matters, in the interest of readability I have split

all the serial stuff into a new file, so when I not get a packet

in over the UART in serial.c, I call this function in main.c

void send_ble_data_to_xlrt(uint8_t *data_ptr, uint16_t len)

{

int err;

err = bt_custom_client_send(&custom_client, data_ptr, len);

if (err != NO_ERROR)

{

LOG_WRN("CUSTOM send timeout");

}

}
This is where I get the error -128 not connected

Eventually I'll put all the BLE stuff in another file

so main is as it should be, a very basic file. Baby steps though.

[Vidar Berg]

Glad to hear you found the reason for the usage fault. Regarding the -ENOTCONN, could you check if it is returned here: 

? The 'conn' object should be assigned at the end of the bt_custom_handles_assign() function.

Also, not directly related to this issue, but while reviewing this function again I noticed that I assigned the RX handle instead of the TX handle here:

DiBosco said:

I don't understand what you're saying here.

Sorry for not being more clear. What I meant to say is that the second COM port (/dev/ttyACM1) exposed by the interface MCU isn't available on this board as there are no nRF pins routed to this UART - USB bridge on the board. You can of course hook up an external FTDI device to the pin headers, or simply use the nRF USB.

From the nRF52840 DK user guide:

(Ref. https://docs.nordicsemi.com/bundle/ug_nrf52840_dk/page/UG/dk/vir_com_port.html )

To enable logging over the nRF USB port, you can try adding the following 2 overlays to the boards folder in your project source directory and do a pristine build.

<PROJ_DIR>/boards/
├── nrf52840dk_nrf52840.conf
└── nrf52840dk_nrf52840.overlay

4555.nrf52840dk_nrf52840.overlay

0636.nrf52840dk_nrf52840.conf

DiBosco said:

Assuming you have more than one UART, can you route the

LOG_WRN & LOG_ERR

traffic to that other UART? If so, how. How and where do you

specify *which* UART

The UART backend does not support individual filtering per device. I.e., you can't define one log level for one UART/USB instance and a different level for another.

[DiBosco]

Vidar Berg said:

Glad to hear you found the reason for the usage fault. Regarding the -ENOTCONN, could you check if it is returned here: 

This morning  it's not giving me the same error and it's allegedly sending messages out to the remote unit. I haven't changed anything, so goodness knows what was going on last night. I do often find with this ecosystem is very flaky. I often have to clean and recompile because it sometimes just doesn't work after a normal compile and I often have to program twice because it fails the first time, so maybe it was the end of a long fruitless day and had I cleaned and rebuilt it would have been OK.

Today, I have found out, from a colleague, that sending "status<CR><LF>" into the main RX characteristic puts the unit  I'm trying to communicate with into ATE mode.

Previously, I've been trying to get this  this really complicated binary comms system it normally uses going. With this binary method the master is constantly sending out frames and expecting responses back and I had to use a specific program. So I was going:

Program using PC_UART <-> nrf52840 bLE <-> Remote Unit BLE

Now I can go:

Cutecom on PC <->nrf52840 bLE <-> Remote Unit BLE

And I don't have to worry about frames, it can all be ASCII based and simple. I can switch on the verbose errors and warnings in central_uart and read them on Cutecom along with any other data coming back over BLE from the custom unit.

I have proven I can get into ATE on the custom unit mode over BLE by using BLE Scanner app on my phone and once I send  status<CR><LF> the unit goes into ATE mode, with the LCD on the front panel confirming it.

However, if I send that via the central_uart app on the 52840DK the remote does not go into ATE mode. So, I hook up the DK running your central_uart app to Cutecom and I send

status<CR><LF>

The central_uart app is clearly getting that exact text in, I can see that by either mirroring the message back to Cutecom or stopping the app with the debugging and looking at what it received.

Once the status request is received by UART into centrral_uart app, this is  called:

err = bt_custom_client_send(&custom_client, data_ptr, len);

I can see with the debugger that

data_ptr points to:

"status<CR><LF>"

len is 8

err = 0 is the response back from the bt_custom_client_send function which suggests is being sent to the remote unit.

ble_data_sent is getting called , which I think is called when the

central_uart app gets confirmation that the remote unit has read

the charctersitic that has been written to locally?

Is your central_uart app on the DK definitely writing to:

#define BT_UUID_CUSTOM_SRV_TX_VAL \

BT_UUID_128_ENCODE(0x651135b0, 0xdfe9, 0x45a2, 0x95c1, 0x46552a8a77e2)

What do all these functions:

uint8_t (*received_tx)(struct bt_custom_client *custom, const uint8_t *data, uint16_t len);

uint8_t (*received_rx)(struct bt_custom_client *custom, const uint8_t *data, uint16_t len);

void (*sent)(struct bt_custom_client *custom, uint8_t err, const uint8_t *data, uint16_t len);

void (*unsubscribed)(struct bt_custom_client *custom);

So and when should they be called? It looks to me,

(although I might be wrong because all the callbacks

within structures [sometimes] within further structures really

are hard to read) that they are set up with

struct bt_custom_client_init_param init = {

.cb = {

.received_tx = ble_data_received_tx,

.received_rx = ble_data_received_rx,

.sent = ble_data_sent,

}

};

and

err = bt_custom_client_init(&custom_client, &init);

But there are four callbacks in the struct

struct bt_custom_client_cb

in custom_client.h and we on;y pass three here.

So maybe they aren't really connected.

So, I guess the big question is:

If the central_uart app is 100% definitely getting the right

string to send to the remote unit and the central_uart app claims
that is has sent the string to the remote unit, and I even,

seemingly get confirmation back that the remote unit has received
something, how can we ascertain it's actually put the right
data into the Tx characteristic? I would hook up the other DK and
see what is received but of course that no longer connects because
of all the new stuff we have in central now.

[DiBosco]

Vidar Berg said:

Sorry for not being more clear. What I meant to say is that the second COM port (/dev/ttyACM1) exposed by the interface MCU isn't available on this board as there are no nRF pins routed to this UART - USB bridge on the board. You can of course hook up an external FTDI device to the pin headers, or simply use the nRF USB.

I still don't understand this.

Can we route the

LOG_ERR etc messages to a specific UART and have one UART for
control comms to the PC that is being sent on via BLE and another

purely for debug data, ie the data currently sent to
LOG_ERR, LOG_WRN and LOG_INF?

If so, surely we could route it to ttyACM0? I can see ttyAM0 is
currently spitting out data because it shows exactly the same

info that I am getting out of the UART I have connected to an

FTDI lead with:

CONFIG_LOG_BACKEND_UART=y

[Vidar Berg]

DiBosco said:

ble_data_sent is getting called , which I think is called when the

central_uart app gets confirmation that the remote unit has read

the charctersitic that has been written to locally?

Unless an ATT error is reported in the callback, the write command will have been sent. Did you check this error code?

DiBosco said:

Is your central_uart app on the DK definitely writing to:

#define BT_UUID_CUSTOM_SRV_TX_VAL \

Did you change the handle value from RX to TX as mentioned in my previous reply?

DiBosco said:

LOG_ERR etc messages to a specific UART and have one UART for
control comms to the PC that is being sent on via BLE and another

purely for debug data, ie the data currently sent to
LOG_ERR, LOG_WRN and LOG_INF?

If so, surely we could route it to ttyACM0? I can see ttyAM0 is
currently spitting out data because it shows exactly the same

You can select which device(s) the UART logger backend should use by modifying the zephyr,console property in the chosen node. The DK board sets this property to zephyr,console = &uart0 by default. Alternatively, if you want to have console (printf, printk) and log (LOG_*) output on separate devices, you can use the zephyr,log-uart property as shown in the Devicetree overlay I shared.  What is not possible is to have the Logger module to print debug messages to one device and only error messages to another. It seems like I misunderstood the question.