BLE Mesh Latency Measurements not Matching Public Nordic Testing Data

[Cam Martell]

I am using 2 nRF528400DK boards. Each board has a unique BLE Mesh sample loaded. The samples were made by modifying the default mesh sample provided by zephyr. One sample acts as a BLE Mesh publisher and the other sample acts as a BLE Mesh subscriber. They each use a custom model, and after being provisioned into the same network via the NRF Mesh app, the publisher sends period basic BLE Mesh messages to the subscriber and the subscriber, after receiving a message, sends the same BLE Mesh message back to the publisher. All messages are unicast, and the samples work as expected without any issues.

For testing, I included a timer on the publisher device. The time is started before publishing a BLE Mesh message and a round-trip latency time is calculated after receiving a response back from the subscriber device. The goal of my testing is to evaluate the Nordic BLE Mesh solution against the publicly posted Nordic BLE Mesh testing blog: https://devzone.nordicsemi.com/nordic/nordic-blog/b/blog/posts/large-scale-bluetooth-mesh-testing#mcetoc_1gsjs1houb

The test results from this blog claim a round-trip latency of around 30ms. I would expect to see similar numbers. However, the timer measurements I see are 60ms - 70ms which is over twice as long. Am I misunderstanding the blog, or is my implementation of round-trip latency measuring off in some way? Were some enhancements made to the testing done by Nordic for this blog that improved latency measurements?

The relevant code for my samples can be found here:

Publisher:

Fullscreen

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

/* main.c - Application main entry point */

/*

* Copyright (c) 2017 Intel Corporation

*

* SPDX-License-Identifier: Apache-2.0

*/

#include <zephyr/sys/printk.h>

#include <zephyr/settings/settings.h>

#include <zephyr/bluetooth/bluetooth.h>

#include <zephyr/bluetooth/mesh.h>

#include "board.h"

#include <stdlib.h> // Include for strtol

#include <zephyr/drivers/gpio.h>

#include <zephyr/drivers/hwinfo.h>

XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

/* main.c - Application main entry point */

/*
 * Copyright (c) 2017 Intel Corporation
 *
 * SPDX-License-Identifier: Apache-2.0
 */

 #include <zephyr/sys/printk.h>

 #include <zephyr/settings/settings.h>
 
 #include <zephyr/bluetooth/bluetooth.h>
 #include <zephyr/bluetooth/mesh.h>
 
 #include "board.h"
 
 #include <stdlib.h> // Include for strtol
 #include <zephyr/drivers/gpio.h>
 #include <zephyr/drivers/hwinfo.h>

 #include <zephyr/bluetooth/mesh/cfg_cli.h>
 
 /** Custom Pub Model ID */
 #define CUSTOM_MODEL_ID	0x0010
 /** Custom Pub Model Op Code Size */
 #define CUSTOM_OP_CODE_SIZE	3
 /** Custom Pub Model Payload Op Code */
 #define CUSTOM_OP	BT_MESH_MODEL_OP_3(0x01, CONFIG_BT_COMPANY_ID)

//  #define MSG_BUFFER_SIZE 3
#define MSG_BUFFER_SIZE 16
 
 static uint8_t hex_to_nibble(char c)
 {
	 if (c >= '0' && c <= '9') {
		 return c - '0';
	 } else if (c >= 'A' && c <= 'F') {
		 return c - 'A' + 10;
	 } else if (c >= 'a' && c <= 'f') {
		 return c - 'a' + 10;
	 } else {
		 return 0; // Invalid character
	 }
 }
 
 void hex_str_to_byte_array(const char *hex_str, uint8_t *byte_array, size_t byte_array_size)
 {
	 for (size_t i = 0; i < byte_array_size; i++) {
		 byte_array[i] = (hex_to_nibble(hex_str[2 * i]) << 4) | hex_to_nibble(hex_str[2 * i + 1]);
	 }
 }
 
 static uint8_t net_key[16];
 static uint8_t dev_key[16];
 static uint8_t app_key[16];
 
 static const uint16_t net_idx = 0x0000;
 static const uint16_t app_idx = 0x0000;
 static const uint32_t iv_index = 0x00000000;
 static uint16_t packet_ID;
 static uint16_t last_packet_ID;
 static uint8_t flags;

static uint16_t subscriber_count = 1;
static uint16_t subscriber_start_addr = 0x0009;
static uint16_t subscriber_current_pub_addr;
static uint32_t subscriber_response_count[1];

static struct k_timer pub_ack_timer;
static uint64_t pub_start_time_ms;
static uint32_t elapsed_time_ms;
static uint64_t total_elapsed_time_ms;
static uint32_t successful_ack_count;
static uint32_t total_packets_sent;
 
static int custom_ack_recv(const struct bt_mesh_model *model,
						   struct bt_mesh_msg_ctx *ctx,
						   struct net_buf_simple *buf)
{
	pub_gpio2_set(true);

	// Calculate the elapsed time
    elapsed_time_ms = k_uptime_get() - pub_start_time_ms;

	// Validate that the payload length is at least 2 bytes
	if (buf->len < 2) {
		printk("Invalid payload length: %u\n", buf->len);
		return -EINVAL;
	}

	// Extract the 2-byte packet ID
	uint16_t received_ID = net_buf_simple_pull_le16(buf);

	// Check if the received packet ID matches the last packet ID sent
	if (received_ID != last_packet_ID) {
		printk("!!!Received packet ID does not match the last packet ID sent!!!\n\n\n");
		return -EINVAL;
	}

	// Update the rolling average
    total_elapsed_time_ms += elapsed_time_ms; // Add the new elapsed time to the total
    successful_ack_count++;                              // Increment the acknowledgment count
    uint32_t rolling_avg_ms = total_elapsed_time_ms / successful_ack_count; // Calculate the rolling average

	// Calculate the success rate
    uint32_t success_rate = 0;
    if (total_packets_sent > 0) {
        success_rate = (successful_ack_count * 100) / total_packets_sent;
    }

	// Track the response for the specific subscriber
    uint16_t subscriber_index = ctx->addr - subscriber_start_addr;
    if (subscriber_index < subscriber_count) {
        subscriber_response_count[subscriber_index]++;
    }

	printk("\n\n");

	return 0; // Return success
}
 
static int publish_update(const struct bt_mesh_model *model);

static struct bt_mesh_cfg_cli cfg_cli = {
};

static void attention_on(const struct bt_mesh_model *mod)
{
	board_led_0_blink();
}

static void attention_off(const struct bt_mesh_model *mod)
{
	board_led_0_blink();
}

static const struct bt_mesh_health_srv_cb health_cb = {
	.attn_on = attention_on,
	.attn_off = attention_off,
};

static struct bt_mesh_health_srv health_srv = {
	.cb = &health_cb,
};
 
BT_MESH_HEALTH_PUB_DEFINE(health_pub, 0);
 
static const struct bt_mesh_model models[] = {
    BT_MESH_MODEL_CFG_SRV,
	BT_MESH_MODEL_CFG_CLI(&cfg_cli),
    BT_MESH_MODEL_HEALTH_SRV(&health_srv, &health_pub),
};

static const struct bt_mesh_model_op custom_model_ops[] = {
    { CUSTOM_OP, 0, custom_ack_recv },
    BT_MESH_MODEL_OP_END,
};

BT_MESH_MODEL_PUB_DEFINE(vendor_model_pub, publish_update, MSG_BUFFER_SIZE);
 
static struct bt_mesh_model vnd_models[] = {
    BT_MESH_MODEL_VND(
        CONFIG_BT_COMPANY_ID, // Vendor-specific company ID
        CUSTOM_MODEL_ID,      // Vendor-specific model ID
        custom_model_ops,        // Operation table
        &vendor_model_pub,                 // No user data needed
		NULL
    ),
};
 
static const struct bt_mesh_elem elements[] = {
	BT_MESH_ELEM(0, models, vnd_models),
};
 
static const struct bt_mesh_comp comp = {
	.cid = BT_COMP_ID_LF,
	.elem = elements,
	.elem_count = ARRAY_SIZE(elements),
};

static int publish_update(const struct bt_mesh_model *model)
{
	if (!model || !model->pub) {
		return -EINVAL;
	}

	/* Reset the message buffer */
    net_buf_simple_reset(model->pub->msg);

    /* Initialize the message buffer with the opcode */
    bt_mesh_model_msg_init(model->pub->msg, CUSTOM_OP);

    /* Add payload to the message */
    net_buf_simple_add_le16(vnd_models[0].pub->msg, packet_ID++); // Add a 16-bit value in little-endian format
	last_packet_ID++;

	/* Set the publication address to the current subscriber */
    model->pub->addr = subscriber_current_pub_addr;

	/* Record the start time */
    pub_start_time_ms = k_uptime_get();

	total_packets_sent++;

	/* Move to the next subscriber */
    subscriber_current_pub_addr++;
    if (subscriber_current_pub_addr >= subscriber_start_addr + subscriber_count) {
        subscriber_current_pub_addr = subscriber_start_addr; // Wrap around to the first subscriber
    }

	return 0;
}

static void configure_publish_params(void)
{
    vendor_model_pub.addr = subscriber_start_addr; // Set the publish start address
    vendor_model_pub.key = app_idx;    // Set the application key index
    vendor_model_pub.ttl = BT_MESH_TTL_DEFAULT; // Set the TTL
	vendor_model_pub.period = BT_MESH_PUB_PERIOD_SEC(3);
}
 
 static const uint8_t dev_uuid[16] = { 0xee, 0xee };

 static const struct bt_mesh_prov prov = {
	 .uuid = dev_uuid,
 }; 
 
 static void bt_ready(int err)
 {
	if (err) {
		printk("Bluetooth init failed (err %d)\n", err);
		return;
	}

	printk("Bluetooth initialized\n");

	err = bt_mesh_init(&prov, &comp);
	if (err) {
		printk("Initializing mesh failed (err %d)\n", err);
		return;
	}

	if (IS_ENABLED(CONFIG_SETTINGS)) {
		settings_load();
	}

	/* Enable provisioning */
	bt_mesh_prov_enable(BT_MESH_PROV_ADV | BT_MESH_PROV_GATT);

	printk("Mesh initialized\n");

	/* Configure publication parameters */
    configure_publish_params();

    /* Check if the device is already provisioned */
    if (bt_mesh_is_provisioned()) {
        printk("Device is already provisioned. Starting periodic publishing...\n");

		/* Prepare the publication message */
		net_buf_simple_reset(vnd_models[0].pub->msg);
		net_buf_simple_add_le16(vnd_models[0].pub->msg, packet_ID++); // Add a 16-bit value in little-endian format
		last_packet_ID++;

        /* Start periodic publication */
        err = bt_mesh_model_publish(&vnd_models[0]);
        if (err) {
            printk("Failed to start periodic publication (err %d)\n", err);
        } else {
            printk("Periodic publication started\n");
        }
    } else {
        printk("Device is not provisioned. Waiting for provisioning...\n");
    }
 }
 
 int main(void)
 {
	// Initialize publish info
	packet_ID = 0x0001;
	last_packet_ID = 0x0000;
	subscriber_current_pub_addr = subscriber_start_addr;
	for (int i = 0; i < subscriber_count; i++) {
		subscriber_response_count[i] = 0;
	}

	// Initialize the timer
    k_timer_init(&pub_ack_timer, NULL, NULL);
	total_elapsed_time_ms = 0;
	successful_ack_count = 0;
	total_packets_sent = 0;

	int err = 0;
 
	 printk("Initializing...\n");

	 /* Initialize LEDs */
	err = leds_init();
	if (err) {
		printk("LEDs init failed (err: %d)\n", err);
		return 0;
	}
 
	 /* Initialize the Bluetooth Subsystem */
	 err = bt_enable(bt_ready);
	 if (err) {
		 printk("Bluetooth init failed (err %d)\n", err);
		 return 0;
	 }
 
	 return 0;
 }
 

Subscriber:

Fullscreen

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

/* main.c - Application main entry point */

/*

* Copyright (c) 2017 Intel Corporation

*

* SPDX-License-Identifier: Apache-2.0

*/

#include <zephyr/sys/printk.h>

#include <zephyr/settings/settings.h>

#include <zephyr/bluetooth/bluetooth.h>

#include <zephyr/bluetooth/mesh.h>

#include "board.h"

#include <stdlib.h> // Include for strtol

#include <zephyr/drivers/gpio.h>

#include <zephyr/drivers/hwinfo.h>

XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

/* main.c - Application main entry point */

/*
 * Copyright (c) 2017 Intel Corporation
 *
 * SPDX-License-Identifier: Apache-2.0
 */

 #include <zephyr/sys/printk.h>

 #include <zephyr/settings/settings.h>
 
 #include <zephyr/bluetooth/bluetooth.h>
 #include <zephyr/bluetooth/mesh.h>
 
 #include "board.h"
 
 #include <stdlib.h> // Include for strtol
 #include <zephyr/drivers/gpio.h>
 #include <zephyr/drivers/hwinfo.h>

 #include <zephyr/bluetooth/mesh/cfg_cli.h>
 
 /** Custom Pub Model ID */
 #define CUSTOM_MODEL_ID	0x0010
 /** Custom Pub Model Op Code Size */
 #define CUSTOM_OP_CODE_SIZE	3
 /** Custom Pub Model Payload Op Code */
 #define CUSTOM_OP	BT_MESH_MODEL_OP_3(0x01, CONFIG_BT_COMPANY_ID)
 
 static uint8_t hex_to_nibble(char c)
 {
	 if (c >= '0' && c <= '9') {
		 return c - '0';
	 } else if (c >= 'A' && c <= 'F') {
		 return c - 'A' + 10;
	 } else if (c >= 'a' && c <= 'f') {
		 return c - 'a' + 10;
	 } else {
		 return 0; // Invalid character
	 }
 }
 
 void hex_str_to_byte_array(const char *hex_str, uint8_t *byte_array, size_t byte_array_size)
 {
	 for (size_t i = 0; i < byte_array_size; i++) {
		 byte_array[i] = (hex_to_nibble(hex_str[2 * i]) << 4) | hex_to_nibble(hex_str[2 * i + 1]);
	 }
 }
 
 static uint8_t net_key[16];
 static uint8_t dev_key[16];
 static uint8_t app_key[16];
 
 static const uint16_t net_idx = 0x0000;
 static const uint16_t app_idx = 0x0000;
 static const uint32_t iv_index = 0x00000000;
 static uint8_t flags;
 
 static int custom_hb_recv(const struct bt_mesh_model *model,
						   struct bt_mesh_msg_ctx *ctx,
						   struct net_buf_simple *buf)
 {
	 pub_gpio1_set(true);
	 
	 // Validate that the payload length is at least 2 bytes
	 if (buf->len < 2) {
		 printk("Invalid payload length: %u\n", buf->len);
		 return -EINVAL;
	 }
 
	 // Extract the 2-byte packet ID
	 uint16_t packet_id = net_buf_simple_pull_le16(buf);
 
	 // Prepare a response message
	 struct net_buf_simple *msg = NET_BUF_SIMPLE(16); // Adjust size as needed
	 bt_mesh_model_msg_init(msg, CUSTOM_OP);         // Use the same or a different opcode
	 net_buf_simple_add_le16(msg, packet_id);    // Example: Increment the packet ID
 
	 // Blink the LED to indicate ACK was sent
	 board_led_0_blink();
 
	 return 0; // Return success
 }
 
 static struct bt_mesh_cfg_cli cfg_cli = {
 };
 
 static void attention_on(const struct bt_mesh_model *mod)
 {
	 board_led_0_blink();
 }
 
 static void attention_off(const struct bt_mesh_model *mod)
 {
	 board_led_0_blink();
 }
 
 static const struct bt_mesh_health_srv_cb health_cb = {
	 .attn_on = attention_on,
	 .attn_off = attention_off,
 };
 
 static struct bt_mesh_health_srv health_srv = {
	 .cb = &health_cb,
 };
 
 BT_MESH_HEALTH_PUB_DEFINE(health_pub, 0);
 
 struct bt_mesh_model models[] = {
	 BT_MESH_MODEL_CFG_SRV,
	 BT_MESH_MODEL_CFG_CLI(&cfg_cli),
	 BT_MESH_MODEL_HEALTH_SRV(&health_srv, &health_pub),
 };
 
 static const struct bt_mesh_model_op custom_hb_ops[] = {
	 { CUSTOM_OP, 0, custom_hb_recv },
	 BT_MESH_MODEL_OP_END,
 };
 
 static struct bt_mesh_model vnd_models[] = {
	 BT_MESH_MODEL_VND(
		 CONFIG_BT_COMPANY_ID, // Vendor-specific company ID
		 CUSTOM_MODEL_ID,      // Vendor-specific model ID
		 custom_hb_ops,        // Operation table
		 NULL,                 // No user data neededy
		 NULL
	 ),
 };
 
 static const struct bt_mesh_elem elements[] = {
	 BT_MESH_ELEM(0, models, vnd_models),
 };
 
 static const struct bt_mesh_comp comp = {
	 .cid = BT_COMP_ID_LF,
	 .elem = elements,
	 .elem_count = ARRAY_SIZE(elements),
 };
 
 static const uint8_t dev_uuid[16] = { 0xdd, 0xdd };

 static const struct bt_mesh_prov prov = {
	 .uuid = dev_uuid,
 }; 
 
 static void bt_ready(int err)
 {
	if (err) {
		printk("Bluetooth init failed (err %d)\n", err);
		return;
	}

	printk("Bluetooth initialized\n");

	err = bt_mesh_init(&prov, &comp);
	if (err) {
		printk("Initializing mesh failed (err %d)\n", err);
		return;
	}

	if (IS_ENABLED(CONFIG_SETTINGS)) {
		settings_load();
	}

	/* This will be a no-op if settings_load() loaded provisioning info */
	bt_mesh_prov_enable(BT_MESH_PROV_ADV | BT_MESH_PROV_GATT);

	printk("Mesh initialized\n");
 }
 
 int main(void)
 {
	 int err = 0;
 
	 printk("Initializing...\n");

	 /* Initialize LEDs */
	err = leds_init();
	if (err) {
		printk("LEDs init failed (err: %d)\n", err);
		return 0;
	}
 
	 /* Initialize the Bluetooth Subsystem */
	 err = bt_enable(bt_ready);
	 if (err) {
		 printk("Bluetooth init failed (err %d)\n", err);
		 return 0;
	 }
 
	 return 0;
 }