When is NUS ready?

[kat829]

Hi!

We have two similar nRF52840 boards and want them to talk via nus_client and nus_server.

At the moment, we consider connection established after client receives the generic bluetooth connected callback and setups nus (below code).

static void connected(struct bt_conn *conn, uint8_t err) {
    // setup NUS
    static struct bt_gatt_exchange_params exchange_params;
    exchange_params.func = exchange_func;
    bt_gatt_exchange_mtu(conn, &exchange_params);
    bt_conn_set_security(conn, BT_SECURITY_L2);
    gatt_discover(conn);
    bt_scan_stop();


    <send first NUS data>
}

Of course, NUS is not ready at that moment, so the message is lost (without any error being reported), just as any messages sent within the next ~1 second.

Is there a way to register a callback that will notify us when NUS is actually ready?

We are using NCS_VERSION=v2.6.1

(I should note that I came across https://devzone.nordicsemi.com/f/nordic-q-a/28208/when-is-nus-ready, but it seems no longer relevant. If I am mistaken, then how can the mentioned handler registered?)

[Sigurd]

Hi!

Do you see any difference with`bt_nus_send(current_conn , data, len);` instead?

[kat829]

The same.

(LogBt originally evaluated to `        err = bt_nus_send(NULL, data, len);`, but supplementing it with a connection pointer doesn't make a difference.)

(Similarly, throwing out the LogBt machinery and sending raw data with `bt_nus_send(conn, data, sizeof(data));` right in the main loop doesn't make a difference.)

In case you spot something in our logs, here they are:

server:

sync:
I: Initialized
I: 2 Sectors of 4096 bytes
I: alloc wra: 0, f38
I: data wra: 0, 160
I: SoftDevice Controller build revision:
I: 36 f0 e5 0e 87 68 48 fb |6....hH.
I: 02 fd 9f 82 cc 32 e5 7b |.....2.{
I: 91 b1 5c ed             |..\.
I: HW Platform: Nordic Semiconductor (0x0002)
I: HW Variant: nRF52x (0x0002)
I: Firmware: Standard Bluetooth controller (0x00) Version 54.58864 Build 1214809870
I: No ID address. App must call settings_load()
Settings: Found peer 'client' with address 92a4ce1198f0
I: Identity: E7:60:F0:D9:98:51 (random)
I: HCI: version 5.4 (0x0d) revision 0x118f, manufacturer 0x0059
I: LMP: version 5.4 (0x0d) subver 0x118f
NUS advertising continued
W: opcode 0x200a status 0x0d
Connected to client (f0:98:11:ce:a4:92)
NUS data sent to client (f0:98:11:ce:a4:92)
NUS data sent to client (f0:98:11:ce:a4:92)
NUS data sent to client (f0:98:11:ce:a4:92)
NUS data sent to client (f0:98:11:ce:a4:92)
NUS data sent to client (f0:98:11:ce:a4:92)
NUS data sent to client (f0:98:11:ce:a4:92)
NUS data sent to client (f0:98:11:ce:a4:92)

client:

client$ ATT error code: 0x0E
Disconnected from server (e7:60:f0:d9:98:51), reason 8
Start scan
Client failed to send data over BLE connection (err -128)
Filters matched: server (e7:60:f0:d9:98:51), connectable:1
Scan connecting: server (e7:60:f0:d9:98:51)
Filters matched: server (e7:60:f0:d9:98:51), connectable:0
Connecting failed: server (e7:60:f0:d9:98:51)
Connected to server (e7:60:f0:d9:98:51)
Failed to set security for server (e7:60:f0:d9:98:51): -12
MTU exchange done with server (e7:60:f0:d9:98:51)
Service discovery completed
server: === Ping 11
server: ---;
server: === Ping 12
server: ---<
server: === Ping 13
server: ---=
server: === Ping 14
server: --->
server: === Ping 15
server: ---?
...

Scenario: server restarts and once nus connection is established, it tries to ping the client. (`---` lines are from a direct raw call to `bt_nus_send(conn, data, sizeof(data))`)

Current relevant code from server main loop is:

    while (NusServerInitialized == false || RightConn == NULL) {
        k_sleep(K_MSEC(1));
    }
    for (int i = 0; i < 30; i++) {
        LogBt("=== Ping %i\n", i);
        uint8_t data[20] = {
            MessageId_Log,
            '-',
            '-',
            '-',
            '0'+i,
            '\n',
            0
        };
        int err = bt_nus_send(RightConn, data, sizeof(data));
        if (err) {
            printk("Failed to send message (err: %d)\n", err);
        }
        k_sleep(K_MSEC(50));

[kat829]

Well, there has to be something wrong about our client initialization sequence.

The trouble seems to be that the NUS server receives the BT_NUS_SEND_STATUS_ENABLED *before* the other device even starts the gatt discovery (see code bellow).

Can you help me understand where exactly subscribing to the RX characteristic of NUS server takes place?

Currently we do something along these lines:

// Here we start a NUS server. (The device communicates over two NUS connections - one as client, one as a server.)

// We also start advertising HID and NUS...

...

// NusClient_Init()
bt_scan_init(&scan_init);
bt_scan_cb_register(&scan_cb);
bt_scan_filter_add(BT_SCAN_FILTER_TYPE_ADDR, &Peers[PeerIdClient].addr);
bt_scan_filter_enable(BT_SCAN_ADDR_FILTER, false);

bt_nus_client_init(&nus_client, &init);
bt_scan_start(BT_SCAN_TYPE_SCAN_ACTIVE);

// connected(...)
// We receive the connected(struct bt_conn *conn, uint8_t err) callback.
// We set some connection parameters (bt_conn_le_param_update and bt_conn_le_data_len_update)

// somewhere at this point, nus server reports BT_NUS_SEND_STATUS_ENABLED and starts sending data

k_sleep(K_MSEC(4000)); // all data sent during this delay are lost

// NusClient_Setup()
bt_gatt_exchange_mtu(conn, &exchange_params);
bt_conn_set_security(conn, BT_SECURITY_L2);
bt_gatt_dm_start(conn, BT_UUID_NUS_SERVICE, &discovery_cb, &nus_client);

...

static void discovery_complete(struct bt_gatt_dm *dm, void *context) {
    struct bt_nus_client *nus = context;
    bt_gatt_dm_data_print(dm);
    bt_nus_handles_assign(dm, nus);
    bt_nus_subscribe_receive(nus);
    bt_gatt_dm_data_release(dm);

    // we consider the client initialized here.
}

[kat829]

Bump?

Tl;dr: current state of affairs is that NUS server reports send_enabled before the client even starts gatt discovery.

[Sigurd]

kat829 said:

NUS server reports send_enabled before the client even starts gatt discovery.

Hva you paired and bonded to the client? If yes, then this might explain why this happens.