Multi reflector channel sounding

[usmanmehmood55]

Hi,

I am trying to do trilateration using one initiator and 3 reflectors. For now I am just trying to get 2 reflectors to work.

Sadly I cannot get the initiator to work like I want it to.

The reflector is running zephyr/samples/bluetooth/channel_sounding/cs_test/reflector, but the advertised names are "channel reflector 1" and "channel reflector 2"

The initiator was modified from zephyr/samples/bluetooth/channel_sounding/cs_test/initiator to use those 2 reflectors.

 

How can I get this to work?

/*
 * Copyright (c) 2024 Nordic Semiconductor ASA
 *
 * SPDX-License-Identifier: Apache-2.0
 */

#include <math.h>
#include <zephyr/sys/byteorder.h>
#include <zephyr/bluetooth/bluetooth.h>
#include <zephyr/bluetooth/cs.h>
#include <zephyr/bluetooth/att.h>
#include <zephyr/bluetooth/gatt.h>
#include "distance_estimation.h"
#include "common.h"
#include "cs_test_params.h"

static K_SEM_DEFINE(sem_results_available, 0, 1);
static K_SEM_DEFINE(sem_test_complete,     0, 1);
static K_SEM_DEFINE(sem_connected,         0, 1);
static K_SEM_DEFINE(sem_disconnected,      0, 1);
static K_SEM_DEFINE(sem_data_received,     0, 1);

static ssize_t on_attr_write_cb(struct bt_conn *conn, const struct bt_gatt_attr *attr, const void *buf, uint16_t len, uint16_t offset, uint8_t flags);
static struct bt_conn *connection;

static uint8_t  n_ap;
static uint8_t  latest_num_steps_reported;
static uint16_t latest_step_data_len;
static uint16_t latest_peer_steps_len;
static uint8_t  latest_local_steps[STEP_DATA_BUF_LEN];
static uint8_t  latest_peer_steps[STEP_DATA_BUF_LEN];

static struct bt_gatt_attr gatt_attributes[] =
{
    BT_GATT_PRIMARY_SERVICE(&step_data_svc_uuid),
    BT_GATT_CHARACTERISTIC(&step_data_char_uuid.uuid, BT_GATT_CHRC_WRITE,
        BT_GATT_PERM_WRITE | BT_GATT_PERM_READ, NULL, on_attr_write_cb, NULL),
};

static struct bt_gatt_service step_data_gatt_service = BT_GATT_SERVICE(gatt_attributes);
static const char reflector1_str[] = "channel reflector 1";
static const char reflector2_str[] = "channel reflector 2";

/* Round-robin state */
static int current_reflector_index = 0;
static const char* reflector_names[] = {reflector1_str, reflector2_str};
static const int num_reflectors = 2;

static ssize_t on_attr_write_cb(struct bt_conn *conn, const struct bt_gatt_attr *attr, const void *buf, uint16_t len, uint16_t offset, uint8_t flags)
{
    if (flags & BT_GATT_WRITE_FLAG_PREPARE)
    {
        return 0;
    }

    if (offset)
    {
        return BT_GATT_ERR(BT_ATT_ERR_INVALID_OFFSET);
    }

    if (len > sizeof(latest_local_steps))
    {
        return BT_GATT_ERR(BT_ATT_ERR_INVALID_ATTRIBUTE_LEN);
    }

    if (flags & BT_GATT_WRITE_FLAG_EXECUTE)
    {
        uint8_t *data = (uint8_t *)buf;

        memcpy(latest_peer_steps, &data[offset], len);
        latest_peer_steps_len = len;
        k_sem_give(&sem_data_received);
    }

    return len;
}

static void subevent_result_cb(struct bt_conn_le_cs_subevent_result *result)
{
    latest_num_steps_reported = result->header.num_steps_reported;
    n_ap = result->header.num_antenna_paths;

    if (result->step_data_buf)
    {
        if (result->step_data_buf->len <= STEP_DATA_BUF_LEN)
        {
            memcpy(latest_local_steps, result->step_data_buf->data,
                   result->step_data_buf->len);
            latest_step_data_len = result->step_data_buf->len;
        }
        else
        {
            printk("Not enough memory to store step data. (%d > %d)\n",
                   result->step_data_buf->len, STEP_DATA_BUF_LEN);
            latest_num_steps_reported = 0;
        }
    }

    if (result->header.procedure_done_status == BT_CONN_LE_CS_PROCEDURE_COMPLETE ||
        result->header.procedure_done_status == BT_CONN_LE_CS_PROCEDURE_ABORTED)
    {
        k_sem_give(&sem_results_available);
    }
}

static void end_cb(void)
{
    k_sem_give(&sem_test_complete);
}

static void mtu_exchange_cb(struct bt_conn *conn, uint8_t err, struct bt_gatt_exchange_params *params)
{
    printk("MTU exchange %s (%u)\n", err == 0U ? "success" : "failed", bt_gatt_get_mtu(conn));
}

static void connected_cb(struct bt_conn *conn, uint8_t err)
{
    char addr[BT_ADDR_LE_STR_LEN];

    (void)bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));
    printk("Connected to %s (err 0x%02X)\n", addr, err);

    __ASSERT(connection == conn, "Unexpected connected callback");

    if (err)
    {
        bt_conn_unref(conn);
        connection = NULL;
    }

    static struct bt_gatt_exchange_params mtu_exchange_params = {.func = mtu_exchange_cb};

    err = bt_gatt_exchange_mtu(connection, &mtu_exchange_params);
    if (err)
    {
        printk("%s: MTU exchange failed (err %d)\n", __func__, err);
    }

    k_sem_give(&sem_connected);
}

static void disconnected_cb(struct bt_conn *conn, uint8_t reason)
{
    printk("Disconnected (reason 0x%02X)\n", reason);

    bt_conn_unref(conn);
    connection = NULL;

    k_sem_give(&sem_disconnected);
}

static bool data_cb(struct bt_data *data, void *user_data)
{
    char *name = user_data;
    uint8_t len;

    switch (data->type)
    {
    case BT_DATA_NAME_SHORTENED:
    case BT_DATA_NAME_COMPLETE:
        len = MIN(data->data_len, NAME_LEN - 1);
        memcpy(name, data->data, len);
        name[len] = '\0';
        return false;
    default:
        return true;
    }
}

static void device_found(const bt_addr_le_t *addr, int8_t rssi, uint8_t type, struct net_buf_simple *ad)
{
    char addr_str[BT_ADDR_LE_STR_LEN];
    char name[NAME_LEN] = {};
    int err;

    if (connection)
    {
        return;
    }

    /* We're only interested in connectable events */
    if (type != BT_GAP_ADV_TYPE_ADV_IND && type != BT_GAP_ADV_TYPE_ADV_DIRECT_IND)
    {
        return;
    }

    bt_data_parse(ad, data_cb, name);

    /* Check if this is the reflector we're looking for in round-robin */
    const char *target_name = reflector_names[current_reflector_index];
    if (strcmp(name, target_name))
    {
        return;
    }

    if (bt_le_scan_stop())
    {
        return;
    }

    printk("Found target reflector %d: %s, connecting...\n", current_reflector_index + 1, name);

    err = bt_conn_le_create(addr, BT_CONN_LE_CREATE_CONN, BT_LE_CONN_PARAM_DEFAULT,
                            &connection);
    if (err)
    {
        printk("Create conn to %s failed (%u)\n", addr_str, err);
    }
}

BT_CONN_CB_DEFINE(conn_cb) =
{
    .connected    = connected_cb,
    .disconnected = disconnected_cb,
};

int main(void)
{
    int err;
    struct bt_le_cs_test_param test_params;

    printk("Starting Multi-Reflector Channel Sounding Demo\n");

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

    struct bt_le_cs_test_cb cs_test_cb =
    {
        .le_cs_test_subevent_data_available = subevent_result_cb,
        .le_cs_test_end_complete            = end_cb,
    };

    err = bt_le_cs_test_cb_register(cs_test_cb);
    if (err)
    {
        printk("Failed to register callbacks (err %d)\n", err);
        return 0;
    }

    err = bt_gatt_service_register(&step_data_gatt_service);
    if (err)
    {
        printk("bt_gatt_service_register() returned err %d\n", err);
        return 0;
    }

    while (true)
    {
        printk("\n=== Starting new CS round ===\n");

        /* Original working logic: Run CS test first */
        while (true)
        {
            k_sleep(K_SECONDS(2));

            test_params = test_params_get(BT_CONN_LE_CS_ROLE_INITIATOR);

            err = bt_le_cs_start_test(&test_params);
            if (err)
            {
                printk("Failed to start CS test (err %d)\n", err);
                return 0;
            }

            k_sem_take(&sem_results_available, K_SECONDS(5));

            err = bt_le_cs_stop_test();
            if (err)
            {
                printk("Failed to stop CS test (err %d)\n", err);
                return 0;
            }

            k_sem_take(&sem_test_complete, K_FOREVER);

            if (latest_num_steps_reported > NUM_MODE_0_STEPS)
            {
                break;
            }
        }

        /* Original working logic: Scan and connect with timeout */
        printk("Scanning for reflector %d: %s\n", current_reflector_index + 1, reflector_names[current_reflector_index]);
        err = bt_le_scan_start(BT_LE_SCAN_ACTIVE_CONTINUOUS, device_found);
        if (err)
        {
            printk("Scanning failed to start (err %d)\n", err);
            return 0;
        }

        /* Wait for connection with timeout */
        err = k_sem_take(&sem_connected, K_SECONDS(10));
        if (err)
        {
            printk("Timeout waiting for reflector %d, moving to next\n", current_reflector_index + 1);
            bt_le_scan_stop();
            current_reflector_index = (current_reflector_index + 1) % num_reflectors;
            continue;
        }

        k_sem_take(&sem_data_received, K_FOREVER);

        /* Calculate distance using actual peer steps length */
        estimate_distance(
            latest_local_steps, latest_step_data_len, latest_peer_steps,
            latest_peer_steps_len,
            n_ap, BT_CONN_LE_CS_ROLE_INITIATOR);

        bt_conn_disconnect(connection, BT_HCI_ERR_REMOTE_USER_TERM_CONN);

        k_sem_take(&sem_disconnected, K_FOREVER);

        /* Move to next reflector in round-robin */
        current_reflector_index = (current_reflector_index + 1) % num_reflectors;
        printk("Next target: reflector %d (%s)\n", current_reflector_index + 1, reflector_names[current_reflector_index]);
        printk("Re-running CS test...\n");
    }

    return 0;
}

CONFIG_BT=y
CONFIG_BT_SMP=y
CONFIG_BT_CENTRAL=y
CONFIG_BT_GAP_AUTO_UPDATE_CONN_PARAMS=n
CONFIG_BT_AUTO_PHY_UPDATE=n
CONFIG_BT_GATT_CLIENT=y
CONFIG_BT_GATT_DYNAMIC_DB=y
CONFIG_BT_ATT_PREPARE_COUNT=3
CONFIG_BT_CHANNEL_SOUNDING=y

CONFIG_BT_BUF_ACL_RX_SIZE=251
CONFIG_BT_BUF_ACL_TX_SIZE=251
CONFIG_BT_L2CAP_TX_MTU=247
CONFIG_BT_MAX_PAIRED=4

CONFIG_MAIN_STACK_SIZE=4096

CONFIG_CBPRINTF_FP_SUPPORT=y
CONFIG_BT_CHANNEL_SOUNDING_TEST=y
CONFIG_CONSOLE=y

I am on nRF Connect SDK v3.0.2

Any help would be much appreciated.

Regards

[Edvin]

Hello,

Did you test the NCS\nrf\samples\bluetooth\channel_sounding_ras_initiator and channel_sounding_ras_reflector? These use an algorithm that gives a bit better accuracy. 

But your question remains the same: "How to do measurements on different devices?"

What do you observe when you try to introduce the second reflector? Does your log say anything?

Best regards,

Edvin

[usmanmehmood55]

 Edvin I used the channel_sounding_ras_reflector and a modified version of channel_sounding_ras_initiator to support 2 reflectors.

channel_sounding_ras_initiator main.c :

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

/** @file
 *  @brief Channel Sounding Initiator with Ranging Requestor sample
 */

#include <math.h>
#include <zephyr/kernel.h>
#include <zephyr/types.h>
#include <zephyr/sys/reboot.h>
#include <zephyr/bluetooth/cs.h>
#include <zephyr/bluetooth/gatt.h>
#include <zephyr/bluetooth/conn.h>
#include <bluetooth/scan.h>
#include <bluetooth/services/ras.h>
#include <bluetooth/gatt_dm.h>
#include <bluetooth/cs_de.h>

#include <dk_buttons_and_leds.h>

#include <zephyr/logging/log.h>

LOG_MODULE_REGISTER(app_main, LOG_LEVEL_INF);

#define CON_STATUS_LED               DK_LED1
#define CS_CONFIG_ID                 0
#define NUM_MODE_0_STEPS             3
#define PROCEDURE_COUNTER_NONE       (-1)
#define DE_SLIDING_WINDOW_SIZE       (10)
#define MAX_AP                       (CONFIG_BT_RAS_MAX_ANTENNA_PATHS)
#define IFFT_RUNNING_AVERAGE_SIZE    5
#define MAX_REFLECTORS               2

#define LOCAL_PROCEDURE_MEM                                                     \
    ((BT_RAS_MAX_STEPS_PER_PROCEDURE * sizeof(struct bt_le_cs_subevent_step)) + \
     (BT_RAS_MAX_STEPS_PER_PROCEDURE * BT_RAS_MAX_STEP_DATA_LEN))

static K_SEM_DEFINE(sem_remote_capabilities_obtained, 0, 1);
static K_SEM_DEFINE(sem_config_created, 0, 1);
static K_SEM_DEFINE(sem_cs_security_enabled, 0, 1);
static K_SEM_DEFINE(sem_connected, 0, 1);
static K_SEM_DEFINE(sem_discovery_done, 0, 1);
static K_SEM_DEFINE(sem_mtu_exchange_done, 0, 1);
static K_SEM_DEFINE(sem_security, 0, 1);
static K_SEM_DEFINE(sem_local_steps, 1, 1);

static K_MUTEX_DEFINE(distance_estimate_buffer_mutex);

static struct bt_conn *connections[MAX_REFLECTORS];
static uint8_t active_connections = 0;
static bt_addr_le_t connected_devices[MAX_REFLECTORS];
static bt_addr_le_t failed_devices[10]; // Track up to 10 failed devices
static uint8_t failed_device_count = 0;
NET_BUF_SIMPLE_DEFINE_STATIC(latest_local_steps, LOCAL_PROCEDURE_MEM);
NET_BUF_SIMPLE_DEFINE_STATIC(latest_peer_steps, BT_RAS_PROCEDURE_MEM);
static int32_t most_recent_local_ranging_counter = PROCEDURE_COUNTER_NONE;
static int32_t dropped_ranging_counter = PROCEDURE_COUNTER_NONE;

static uint8_t buffer_index;
static uint8_t buffer_num_valid;
static cs_de_dist_estimates_t distance_estimate_buffer[MAX_REFLECTORS][MAX_AP][DE_SLIDING_WINDOW_SIZE];

// Running average buffer for IFFT distances
static float ifft_running_average_buffer[MAX_REFLECTORS][MAX_AP][IFFT_RUNNING_AVERAGE_SIZE];
static uint8_t ifft_running_average_index[MAX_REFLECTORS][MAX_AP];
static uint8_t ifft_running_average_count[MAX_REFLECTORS][MAX_AP];

static void store_distance_estimates(uint8_t reflector_index, cs_de_report_t *p_report)
{
    int lock_state = k_mutex_lock(&distance_estimate_buffer_mutex, K_FOREVER);

    __ASSERT_NO_MSG(lock_state == 0);

    for (uint8_t ap = 0; ap < p_report->n_ap; ap++)
    {
        memcpy(&distance_estimate_buffer[reflector_index][ap][buffer_index],
               &p_report->distance_estimates[ap], sizeof(cs_de_dist_estimates_t));
    }

    buffer_index = (buffer_index + 1) % DE_SLIDING_WINDOW_SIZE;

    if (buffer_num_valid < DE_SLIDING_WINDOW_SIZE)
    {
        buffer_num_valid++;
    }

    k_mutex_unlock(&distance_estimate_buffer_mutex);
}

static cs_de_dist_estimates_t get_distance(uint8_t reflector_index, uint8_t ap)
{
    cs_de_dist_estimates_t averaged_result = {};
    uint8_t num_ifft = 0;
    uint8_t num_phase_slope = 0;
    uint8_t num_rtt = 0;

    int lock_state = k_mutex_lock(&distance_estimate_buffer_mutex, K_FOREVER);

    __ASSERT_NO_MSG(lock_state == 0);

    for (uint8_t i = 0; i < buffer_num_valid; i++)
    {
        if (isfinite(distance_estimate_buffer[reflector_index][ap][i].ifft))
        {
            num_ifft++;
            averaged_result.ifft += distance_estimate_buffer[reflector_index][ap][i].ifft;
        }
        if (isfinite(distance_estimate_buffer[reflector_index][ap][i].phase_slope))
        {
            num_phase_slope++;
            averaged_result.phase_slope += distance_estimate_buffer[reflector_index][ap][i].phase_slope;
        }
        if (isfinite(distance_estimate_buffer[reflector_index][ap][i].rtt))
        {
            num_rtt++;
            averaged_result.rtt += distance_estimate_buffer[reflector_index][ap][i].rtt;
        }
    }

    k_mutex_unlock(&distance_estimate_buffer_mutex);

    if (num_ifft)
    {
        averaged_result.ifft /= num_ifft;
    }

    if (num_phase_slope)
    {
        averaged_result.phase_slope /= num_phase_slope;
    }

    if (num_rtt)
    {
        averaged_result.rtt /= num_rtt;
    }

    return averaged_result;
}

static float update_ifft_running_average(uint8_t reflector_index, uint8_t ap, float new_ifft_value)
{
    float sum = 0.0f;

    // Add new value to the buffer
    ifft_running_average_buffer[reflector_index][ap][ifft_running_average_index[reflector_index][ap]] = new_ifft_value;
    ifft_running_average_index[reflector_index][ap] = (ifft_running_average_index[reflector_index][ap] + 1) % IFFT_RUNNING_AVERAGE_SIZE;

    // Update count if buffer not full yet
    if (ifft_running_average_count[reflector_index][ap] < IFFT_RUNNING_AVERAGE_SIZE)
    {
        ifft_running_average_count[reflector_index][ap]++;
    }

    // Calculate running average
    for (uint8_t i = 0; i < ifft_running_average_count[reflector_index][ap]; i++)
    {
        sum += ifft_running_average_buffer[reflector_index][ap][i];
    }

    return sum / ifft_running_average_count[reflector_index][ap];
}

static void ranging_data_get_complete_cb(struct bt_conn *conn, uint16_t ranging_counter, int err)
{
    // Find which reflector this connection belongs to
    uint8_t reflector_index = 0;
    for (uint8_t i = 0; i < active_connections; i++)
    {
        if (connections[i] == conn)
        {
            reflector_index = i;
            break;
        }
    }

    if (err)
    {
        LOG_ERR("Error when getting ranging data with ranging counter %d (err %d)",
                ranging_counter, err);
        return;
    }

    LOG_DBG("Ranging data get completed for ranging counter %d from reflector %d",
            ranging_counter, reflector_index);

    /* This struct is static to avoid putting it on the stack (it's very large) */
    static cs_de_report_t cs_de_report;

    cs_de_populate_report(&latest_local_steps, &latest_peer_steps, BT_CONN_LE_CS_ROLE_INITIATOR,
                          &cs_de_report);

    net_buf_simple_reset(&latest_local_steps);
    net_buf_simple_reset(&latest_peer_steps);
    k_sem_give(&sem_local_steps);

    cs_de_quality_t quality = cs_de_calc(&cs_de_report);

    if (quality == CS_DE_QUALITY_OK)
    {
        for (uint8_t ap = 0; ap < cs_de_report.n_ap; ap++)
        {
            if (cs_de_report.tone_quality[ap] == CS_DE_TONE_QUALITY_OK)
            {
                store_distance_estimates(reflector_index, &cs_de_report);
            }
        }
    }
}

static void subevent_result_cb(struct bt_conn *conn, struct bt_conn_le_cs_subevent_result *result)
{
    if (dropped_ranging_counter == result->header.procedure_counter)
    {
        return;
    }

    if (most_recent_local_ranging_counter != bt_ras_rreq_get_ranging_counter(result->header.procedure_counter))
    {
        int sem_state = k_sem_take(&sem_local_steps, K_NO_WAIT);

        if (sem_state < 0)
        {
            dropped_ranging_counter = result->header.procedure_counter;
            LOG_DBG("Dropped subevent results due to unfinished ranging data request.");
            return;
        }

        most_recent_local_ranging_counter =
            bt_ras_rreq_get_ranging_counter(result->header.procedure_counter);
    }

    if (result->header.subevent_done_status == BT_CONN_LE_CS_SUBEVENT_ABORTED)
    {
        /* The steps from this subevent will not be used. */
    }
    else if (result->step_data_buf)
    {
        if (result->step_data_buf->len <= net_buf_simple_tailroom(&latest_local_steps))
        {
            uint16_t len = result->step_data_buf->len;
            uint8_t *step_data = net_buf_simple_pull_mem(result->step_data_buf, len);

            net_buf_simple_add_mem(&latest_local_steps, step_data, len);
        }
        else
        {
            LOG_ERR("Not enough memory to store step data. (%d > %d)",
                    latest_local_steps.len + result->step_data_buf->len,
                    latest_local_steps.size);
            net_buf_simple_reset(&latest_local_steps);
            dropped_ranging_counter = result->header.procedure_counter;
            return;
        }
    }

    dropped_ranging_counter = PROCEDURE_COUNTER_NONE;

    if (result->header.procedure_done_status == BT_CONN_LE_CS_PROCEDURE_COMPLETE)
    {
        most_recent_local_ranging_counter =
            bt_ras_rreq_get_ranging_counter(result->header.procedure_counter);
    }
    else if (result->header.procedure_done_status == BT_CONN_LE_CS_PROCEDURE_ABORTED)
    {
        LOG_WRN("Procedure %u aborted", result->header.procedure_counter);
        net_buf_simple_reset(&latest_local_steps);
        k_sem_give(&sem_local_steps);
    }
}

static void ranging_data_ready_cb(struct bt_conn *conn, uint16_t ranging_counter)
{
    LOG_DBG("Ranging data ready %i", ranging_counter);

    if (ranging_counter == most_recent_local_ranging_counter)
    {
        int err = bt_ras_rreq_cp_get_ranging_data(conn, &latest_peer_steps,
                                                  ranging_counter,
                                                  ranging_data_get_complete_cb);
        if (err)
        {
            LOG_ERR("Get ranging data failed (err %d)", err);
            net_buf_simple_reset(&latest_local_steps);
            net_buf_simple_reset(&latest_peer_steps);
            k_sem_give(&sem_local_steps);
        }
    }
}

static void ranging_data_overwritten_cb(struct bt_conn *conn, uint16_t ranging_counter)
{
    LOG_INF("Ranging data overwritten %i", ranging_counter);
}

static void mtu_exchange_cb(struct bt_conn *conn, uint8_t err,
                            struct bt_gatt_exchange_params *params)
{
    if (err)
    {
        LOG_ERR("MTU exchange failed (err %d)", err);
        return;
    }

    LOG_INF("MTU exchange success (%u)", bt_gatt_get_mtu(conn));
    k_sem_give(&sem_mtu_exchange_done);
}

static void discovery_completed_cb(struct bt_gatt_dm *dm, void *context)
{
    int err;

    LOG_INF("The discovery procedure succeeded");

    struct bt_conn *conn = bt_gatt_dm_conn_get(dm);

    bt_gatt_dm_data_print(dm);

    err = bt_ras_rreq_alloc_and_assign_handles(dm, conn);
    if (err)
    {
        LOG_ERR("RAS RREQ alloc init failed (err %d)", err);
    }

    err = bt_gatt_dm_data_release(dm);
    if (err)
    {
        LOG_ERR("Could not release the discovery data (err %d)", err);
    }

    k_sem_give(&sem_discovery_done);
}

static void discovery_service_not_found_cb(struct bt_conn *conn, void *context)
{
    LOG_INF("The service could not be found during the discovery, disconnecting");
    bt_conn_disconnect(conn, BT_HCI_ERR_REMOTE_USER_TERM_CONN);
}

static void discovery_error_found_cb(struct bt_conn *conn, int err, void *context)
{
    LOG_INF("The discovery procedure failed (err %d)", err);
    bt_conn_disconnect(conn, BT_HCI_ERR_REMOTE_USER_TERM_CONN);
}

static struct bt_gatt_dm_cb discovery_cb = {
    .completed = discovery_completed_cb,
    .service_not_found = discovery_service_not_found_cb,
    .error_found = discovery_error_found_cb,
};

static void security_changed(struct bt_conn *conn, bt_security_t level, enum bt_security_err err)
{
    char addr[BT_ADDR_LE_STR_LEN];

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

    if (err)
    {
        LOG_ERR("Security failed: %s level %u err %d %s", addr, level, err,
                bt_security_err_to_str(err));
        return;
    }

    LOG_INF("Security changed: %s level %u", addr, level);
    k_sem_give(&sem_security);
}

static bool le_param_req(struct bt_conn *conn, struct bt_le_conn_param *param)
{
    /* Ignore peer parameter preferences. */
    return false;
}

static void connected_cb(struct bt_conn *conn, uint8_t err)
{
    char addr[BT_ADDR_LE_STR_LEN];

    (void)bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));
    LOG_INF("Connected to %s (err 0x%02X)", addr, err);

    if (err)
    {
        bt_conn_unref(conn);
        return;
    }

    // Store the connection in the array
    if (active_connections < MAX_REFLECTORS)
    {
        connections[active_connections] = bt_conn_ref(conn);
        // Store the device address
        bt_addr_le_copy(&connected_devices[active_connections], bt_conn_get_dst(conn));
        LOG_INF("Stored connection for reflector %d", active_connections);
        active_connections++;

        // Continue scanning if we haven't found all reflectors yet
        if (active_connections < MAX_REFLECTORS)
        {
            LOG_INF("Continuing to scan for more reflectors (%d/%d found)",
                    active_connections, MAX_REFLECTORS);
            int err = bt_scan_start(BT_SCAN_TYPE_SCAN_PASSIVE);
            if (err)
            {
                LOG_ERR("Failed to restart scanning (err %d)", err);
            }
        }
        else
        {
            LOG_INF("All reflectors found, stopping scan");
            bt_scan_stop();
        }
    }

    k_sem_give(&sem_connected);

    dk_set_led_on(CON_STATUS_LED);
}

static void disconnected_cb(struct bt_conn *conn, uint8_t reason)
{
    LOG_INF("Disconnected (reason 0x%02X)", reason);

    // Find and remove the connection from our array
    for (uint8_t i = 0; i < active_connections; i++)
    {
        if (connections[i] == conn)
        {
            bt_conn_unref(connections[i]);
            connections[i] = NULL;
            LOG_INF("Removed connection for reflector %d", i);
            break;
        }
    }

    bt_conn_unref(conn);
    dk_set_led_off(CON_STATUS_LED);

    sys_reboot(SYS_REBOOT_COLD);
}

static void remote_capabilities_cb(struct bt_conn *conn,
                                   uint8_t status,
                                   struct bt_conn_le_cs_capabilities *params)
{
    ARG_UNUSED(conn);
    ARG_UNUSED(params);

    if (status == BT_HCI_ERR_SUCCESS)
    {
        LOG_INF("CS capability exchange completed.");
        k_sem_give(&sem_remote_capabilities_obtained);
    }
    else
    {
        LOG_WRN("CS capability exchange failed. (HCI status 0x%02x)", status);
    }
}

static void config_create_cb(struct bt_conn *conn,
                             uint8_t status,
                             struct bt_conn_le_cs_config *config)
{
    ARG_UNUSED(conn);

    if (status == BT_HCI_ERR_SUCCESS)
    {
        LOG_INF("CS config creation complete. ID: %d", config->id);
        k_sem_give(&sem_config_created);
    }
    else
    {
        LOG_WRN("CS config creation failed. (HCI status 0x%02x)", status);
    }
}

static void security_enable_cb(struct bt_conn *conn, uint8_t status)
{
    ARG_UNUSED(conn);

    if (status == BT_HCI_ERR_SUCCESS)
    {
        LOG_INF("CS security enabled.");
        k_sem_give(&sem_cs_security_enabled);
    }
    else
    {
        LOG_WRN("CS security enable failed. (HCI status 0x%02x)", status);
    }
}

static void procedure_enable_cb(struct bt_conn *conn,
                                uint8_t status,
                                struct bt_conn_le_cs_procedure_enable_complete *params)
{
    ARG_UNUSED(conn);

    if (status == BT_HCI_ERR_SUCCESS)
    {
        if (params->state == 1)
        {
            LOG_INF("CS procedures enabled:\n"
                    " - config ID: %u\n"
                    " - antenna configuration index: %u\n"
                    " - TX power: %d dbm\n"
                    " - subevent length: %u us\n"
                    " - subevents per event: %u\n"
                    " - subevent interval: %u\n"
                    " - event interval: %u\n"
                    " - procedure interval: %u\n"
                    " - procedure count: %u\n"
                    " - maximum procedure length: %u",
                    params->config_id, params->tone_antenna_config_selection,
                    params->selected_tx_power, params->subevent_len,
                    params->subevents_per_event, params->subevent_interval,
                    params->event_interval, params->procedure_interval,
                    params->procedure_count, params->max_procedure_len);
        }
        else
        {
            LOG_INF("CS procedures disabled.");
        }
    }
    else
    {
        LOG_WRN("CS procedures enable failed. (HCI status 0x%02x)", status);
    }
}

static bool is_device_already_connected(const bt_addr_le_t *addr)
{
    for (uint8_t i = 0; i < active_connections; i++)
    {
        if (bt_addr_le_cmp(&connected_devices[i], addr) == 0)
        {
            return true;
        }
    }
    return false;
}

static bool is_device_already_failed(const bt_addr_le_t *addr)
{
    for (uint8_t i = 0; i < failed_device_count; i++)
    {
        if (bt_addr_le_cmp(&failed_devices[i], addr) == 0)
        {
            return true;
        }
    }
    return false;
}

static void scan_filter_match(struct bt_scan_device_info *device_info,
                              struct bt_scan_filter_match *filter_match, bool connectable)
{
    char addr[BT_ADDR_LE_STR_LEN];
    char device_name[32] = {0};

    bt_addr_le_to_str(device_info->recv_info->addr, addr, sizeof(addr));

    // Check if we've already connected to this device
    if (is_device_already_connected(device_info->recv_info->addr))
    {
        LOG_INF("Skipping already connected device: %s", addr);
        return;
    }

    // Check if we've already failed to connect to this device
    if (is_device_already_failed(device_info->recv_info->addr))
    {
        LOG_INF("Skipping failed device: %s", addr);
        return;
    }

    // Try to get device name from scan data
    const uint8_t *data = device_info->adv_data->data;
    uint8_t len = device_info->adv_data->len;

    for (int i = 0; i < len;)
    {
        uint8_t field_len = data[i];
        uint8_t field_type = data[i + 1];

        if (field_type == BT_DATA_NAME_COMPLETE)
        {
            if (field_len > 1 && (i + 2 + field_len - 1) <= len)
            {
                memcpy(device_name, &data[i + 2], field_len - 1);
                device_name[field_len - 1] = '\0';
                break;
            }
        }
        i += field_len + 1;
    }

    LOG_INF("Filters matched. Address: %s, Name: %s, connectable: %d (current connections: %d/%d)",
            addr, device_name[0] ? device_name : "Unknown", connectable, active_connections, MAX_REFLECTORS);
}

static void scan_connecting_error(struct bt_scan_device_info *device_info)
{
    char addr[BT_ADDR_LE_STR_LEN];
    bt_addr_le_to_str(device_info->recv_info->addr, addr, sizeof(addr));

    LOG_INF("Connecting failed to %s, adding to failed list", addr);

    // Add to failed devices list if we have space
    if (failed_device_count < 10)
    {
        bt_addr_le_copy(&failed_devices[failed_device_count], device_info->recv_info->addr);
        failed_device_count++;
        LOG_INF("Added %s to failed devices list (total failed: %d)", addr, failed_device_count);
    }

    // Only restart scanning if we haven't found all reflectors yet
    if (active_connections < MAX_REFLECTORS)
    {
        LOG_INF("Restarting scanning for more reflectors");
        // Add a small delay before restarting scan to avoid overwhelming the device
        k_sleep(K_MSEC(1000));
        int err = bt_scan_start(BT_SCAN_TYPE_SCAN_PASSIVE);
        if (err)
        {
            LOG_ERR("Failed to restart scanning (err %i)", err);
        }
    }
}

static void scan_connecting(struct bt_scan_device_info *device_info, struct bt_conn *conn)
{
    char addr[BT_ADDR_LE_STR_LEN];
    bt_addr_le_to_str(device_info->recv_info->addr, addr, sizeof(addr));

    LOG_INF("Attempting to connect to %s", addr);
}

BT_SCAN_CB_INIT(scan_cb, scan_filter_match, NULL, scan_connecting_error, scan_connecting);

static int scan_init(void)
{
    int err;

    struct bt_scan_init_param param = {
        .scan_param = NULL, .conn_param = BT_LE_CONN_PARAM_DEFAULT, .connect_if_match = 1};

    bt_scan_init(&param);
    bt_scan_cb_register(&scan_cb);

    err = bt_scan_filter_add(BT_SCAN_FILTER_TYPE_UUID, BT_UUID_RANGING_SERVICE);
    if (err)
    {
        LOG_ERR("Scanning filters cannot be set (err %d)", err);
        return err;
    }

    err = bt_scan_filter_enable(BT_SCAN_UUID_FILTER, false);
    if (err)
    {
        LOG_ERR("Filters cannot be turned on (err %d)", err);
        return err;
    }

    return 0;
}

BT_CONN_CB_DEFINE(conn_cb) = 
{
    .connected                               = connected_cb,
    .disconnected                            = disconnected_cb,
    .le_param_req                            = le_param_req,
    .security_changed                        = security_changed,
    .le_cs_read_remote_capabilities_complete = remote_capabilities_cb,
    .le_cs_config_complete                   = config_create_cb,
    .le_cs_security_enable_complete          = security_enable_cb,
    .le_cs_procedure_enable_complete         = procedure_enable_cb,
    .le_cs_subevent_data_available           = subevent_result_cb,
};

static void setup_reflector_connection(struct bt_conn *conn, uint8_t reflector_index)
{
    int err;

    LOG_INF("Setting up reflector connection %d", reflector_index);

    err = bt_conn_set_security(conn, BT_SECURITY_L2);
    if (err)
    {
        LOG_ERR("Failed to encrypt connection (err %d)", err);
        return;
    }

    k_sem_take(&sem_security, K_FOREVER);

    static struct bt_gatt_exchange_params mtu_exchange_params = {.func = mtu_exchange_cb};

    bt_gatt_exchange_mtu(conn, &mtu_exchange_params);

    k_sem_take(&sem_mtu_exchange_done, K_FOREVER);

    err = bt_gatt_dm_start(conn, BT_UUID_RANGING_SERVICE, &discovery_cb, NULL);
    if (err)
    {
        LOG_ERR("Discovery failed (err %d)", err);
        return;
    }

    k_sem_take(&sem_discovery_done, K_FOREVER);

    const struct bt_le_cs_set_default_settings_param default_settings = {
        .enable_initiator_role = true,
        .enable_reflector_role = false,
        .cs_sync_antenna_selection = BT_LE_CS_ANTENNA_SELECTION_OPT_REPETITIVE,
        .max_tx_power = BT_HCI_OP_LE_CS_MAX_MAX_TX_POWER,
    };

    err = bt_le_cs_set_default_settings(conn, &default_settings);
    if (err)
    {
        LOG_ERR("Failed to configure default CS settings (err %d)", err);
        return;
    }

    err = bt_ras_rreq_rd_overwritten_subscribe(conn, ranging_data_overwritten_cb);
    if (err)
    {
        LOG_ERR("RAS RREQ ranging data overwritten subscribe failed (err %d)", err);
        return;
    }

    err = bt_ras_rreq_rd_ready_subscribe(conn, ranging_data_ready_cb);
    if (err)
    {
        LOG_ERR("RAS RREQ ranging data ready subscribe failed (err %d)", err);
        return;
    }

    err = bt_ras_rreq_on_demand_rd_subscribe(conn);
    if (err)
    {
        LOG_ERR("RAS RREQ On-demand ranging data subscribe failed (err %d)", err);
        return;
    }

    err = bt_ras_rreq_cp_subscribe(conn);
    if (err)
    {
        LOG_ERR("RAS RREQ CP subscribe failed (err %d)", err);
        return;
    }

    err = bt_le_cs_read_remote_supported_capabilities(conn);
    if (err)
    {
        LOG_ERR("Failed to exchange CS capabilities (err %d)", err);
        return;
    }

    k_sem_take(&sem_remote_capabilities_obtained, K_FOREVER);

    struct bt_le_cs_create_config_params config_params = 
    {
        .id                     = CS_CONFIG_ID,
        .main_mode_type         = BT_CONN_LE_CS_MAIN_MODE_2,
        .sub_mode_type          = BT_CONN_LE_CS_SUB_MODE_1,
        .min_main_mode_steps    = 2,
        .max_main_mode_steps    = 5,
        .main_mode_repetition   = 0,
        .mode_0_steps           = NUM_MODE_0_STEPS,
        .role                   = BT_CONN_LE_CS_ROLE_INITIATOR,
        .rtt_type               = BT_CONN_LE_CS_RTT_TYPE_AA_ONLY,
        .cs_sync_phy            = BT_CONN_LE_CS_SYNC_1M_PHY,
        .channel_map_repetition = 3,
        .channel_selection_type = BT_CONN_LE_CS_CHSEL_TYPE_3B,
        .ch3c_shape             = BT_CONN_LE_CS_CH3C_SHAPE_HAT,
        .ch3c_jump              = 2,
    };

    bt_le_cs_set_valid_chmap_bits(config_params.channel_map);

    err = bt_le_cs_create_config(conn, &config_params,
                                 BT_LE_CS_CREATE_CONFIG_CONTEXT_LOCAL_AND_REMOTE);
    if (err)
    {
        LOG_ERR("Failed to create CS config (err %d)", err);
        return;
    }

    k_sem_take(&sem_config_created, K_FOREVER);

    err = bt_le_cs_security_enable(conn);
    if (err)
    {
        LOG_ERR("Failed to start CS Security (err %d)", err);
        return;
    }

    k_sem_take(&sem_cs_security_enabled, K_FOREVER);

    const struct bt_le_cs_set_procedure_parameters_param procedure_params =
    {
        .config_id                     = CS_CONFIG_ID,
        .max_procedure_len             = 1000,
        .min_procedure_interval        = 10,
        .max_procedure_interval        = 10,
        .max_procedure_count           = 0,
        .min_subevent_len              = 60000,
        .max_subevent_len              = 60000,
        .tone_antenna_config_selection = BT_LE_CS_TONE_ANTENNA_CONFIGURATION_A1_B1,
        .phy                           = BT_LE_CS_PROCEDURE_PHY_1M,
        .tx_power_delta                = 0x80,
        .preferred_peer_antenna        = BT_LE_CS_PROCEDURE_PREFERRED_PEER_ANTENNA_1,
        .snr_control_initiator         = BT_LE_CS_SNR_CONTROL_NOT_USED,
        .snr_control_reflector         = BT_LE_CS_SNR_CONTROL_NOT_USED,
    };

    err = bt_le_cs_set_procedure_parameters(conn, &procedure_params);
    if (err)
    {
        LOG_ERR("Failed to set procedure parameters (err %d)", err);
        return;
    }

    struct bt_le_cs_procedure_enable_param params = {
        .config_id = CS_CONFIG_ID,
        .enable = 1,
    };

    err = bt_le_cs_procedure_enable(conn, &params);
    if (err)
    {
        LOG_ERR("Failed to enable CS procedures (err %d)", err);
        return;
    }

    LOG_INF("Reflector connection %d setup complete", reflector_index);
}

int main(void)
{
    int err;

    LOG_INF("Starting Channel Sounding Initiator Sample");

    dk_leds_init();

    err = bt_enable(NULL);
    if (err)
    {
        LOG_ERR("Bluetooth init failed (err %d)", err);
        return 0;
    }

    err = scan_init();
    if (err)
    {
        LOG_ERR("Scan init failed (err %d)", err);
        return 0;
    }

    err = bt_scan_start(BT_SCAN_TYPE_SCAN_PASSIVE);
    if (err)
    {
        LOG_ERR("Scanning failed to start (err %i)", err);
        return 0;
    }

    // Wait for all reflector connections
    LOG_INF("Waiting for %d reflector connections...", MAX_REFLECTORS);

    // Add a timeout mechanism - wait up to 30 seconds for all connections
    int timeout_count = 0;
    const int max_timeout = 300;   // 30 seconds at 100ms intervals
    const int retry_interval = 50; // Retry failed devices every 5 seconds

    while (active_connections < MAX_REFLECTORS && timeout_count < max_timeout)
    {
        // Wait for connection with timeout
        if (k_sem_take(&sem_connected, K_MSEC(100)) == 0)
        {
            LOG_INF("Connected to reflector %d (%d/%d total)",
                    active_connections - 1, active_connections, MAX_REFLECTORS);
        }
        else
        {
            timeout_count++;

            // Clear failed devices list periodically to allow retrying
            if (timeout_count % retry_interval == 0 && failed_device_count > 0)
            {
                LOG_INF("Clearing failed devices list to retry connections");
                failed_device_count = 0;
            }

            if (timeout_count % 100 == 0)
            { // Log every 10 seconds
                LOG_INF("Still waiting for reflectors... (%d/%d found, timeout: %d/%d, failed devices: %d)",
                        active_connections, MAX_REFLECTORS, timeout_count, max_timeout, failed_device_count);
            }
        }
    }

    if (active_connections < MAX_REFLECTORS)
    {
        LOG_WRN("Timeout waiting for all reflectors. Only found %d/%d",
                active_connections, MAX_REFLECTORS);
        if (active_connections == 0)
        {
            LOG_ERR("No reflectors found! Check if reflector devices are advertising properly.");
            return 0;
        }
        LOG_INF("Proceeding with available reflectors...");
    }

    LOG_INF("Setup complete for %d reflectors, starting ranging", active_connections);

    // Setup each reflector connection
    for (uint8_t i = 0; i < active_connections; i++)
    {
        setup_reflector_connection(connections[i], i);
    }

    while (true)
    {
        k_sleep(K_MSEC(1000)); // Faster update rate: 100ms instead of 500ms

        // Process distance estimates for all reflectors
        for (uint8_t reflector = 0; reflector < active_connections; reflector++)
        {
            if (buffer_num_valid != 0)
            {
                for (uint8_t ap = 0; ap < MAX_AP; ap++)
                {
                    cs_de_dist_estimates_t distance_on_ap = get_distance(reflector, ap);

                    // Update running average for IFFT distance
                    float ifft_running_avg = update_ifft_running_average(reflector, ap, distance_on_ap.ifft);

                    LOG_INF("Reflector %d - Distance estimates on antenna path %u: ifft: %f (avg: %f), "
                            "phase_slope: %f, rtt: %f",
                            reflector, ap, (double)distance_on_ap.ifft, (double)ifft_running_avg,
                            (double)distance_on_ap.phase_slope,
                            (double)distance_on_ap.rtt);
                }
            }
        }

        LOG_INF("Sleeping for 1000 ms...");
    }

    return 0;
}

channel_sounding_ras_initiator prj.conf :

#
# Copyright (c) 2024 Nordic Semiconductor ASA
#
# SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
#

CONFIG_NCS_SAMPLES_DEFAULTS=y
CONFIG_DK_LIBRARY=y

CONFIG_BT=y
CONFIG_BT_SMP=y
CONFIG_BT_CENTRAL=y
CONFIG_BT_MAX_CONN=4
CONFIG_BT_BONDABLE=n

CONFIG_BT_GATT_CLIENT=y
CONFIG_BT_GATT_DYNAMIC_DB=y

CONFIG_BT_CHANNEL_SOUNDING=y
CONFIG_BT_RAS=y
CONFIG_BT_RAS_RREQ=y

CONFIG_BT_SCAN=y
CONFIG_BT_SCAN_FILTER_ENABLE=y
CONFIG_BT_SCAN_UUID_CNT=1

# The Ranging Profile recommends a MTU of at least 247 octets.
CONFIG_BT_L2CAP_TX_MTU=498
CONFIG_BT_BUF_ACL_TX_SIZE=502
CONFIG_BT_BUF_ACL_RX_SIZE=502
CONFIG_BT_ATT_PREPARE_COUNT=3
CONFIG_BT_CTLR_DATA_LENGTH_MAX=251

# This reduces RAM usage. Additional RAM is needed to support optional
# features such as mode 3 or multiantenna. Change or remove these if
# using those features
CONFIG_BT_RAS_MODE_3_SUPPORTED=n
CONFIG_BT_RAS_MAX_ANTENNA_PATHS=1
CONFIG_BT_CTLR_SDC_CS_MAX_ANTENNA_PATHS=1
CONFIG_BT_CTLR_SDC_CS_NUM_ANTENNAS=1
CONFIG_BT_CTLR_SDC_CS_STEP_MODE3=n

# This size assumes the largest step size is mode 2 with one antenna path:
# 12 bytes * 160 steps in a subevent. Change or remove this if using mode 3
# or multiantenna.
CONFIG_BT_CHANNEL_SOUNDING_REASSEMBLY_BUFFER_SIZE=1920

# This allows CS and ACL to use different PHYs
CONFIG_BT_TRANSMIT_POWER_CONTROL=y

# This improves the performance of floating-point operations
CONFIG_FPU=y
CONFIG_FPU_SHARING=y

CONFIG_CBPRINTF_FP_SUPPORT=y

CONFIG_BT_CS_DE=y
CONFIG_BT_CS_DE_512_NFFT=y

The logs on initiator side :

(you will notice that one of the reflectors always shows 0 in distance)

*** Booting nRF Connect SDK v3.0.2-89ba1294ac9b ***
*** Using Zephyr OS v4.0.99-f791c49f492c ***
I: Starting Channel Sounding Initiator Sample
I: SoftDevice Controller build revision: 
I: 89 9a 50 8a 95 01 9c 58 |..P....X
I: fc 39 d2 c1 10 04 ee 02 |.9......
I: 64 ce 25 be             |d.%.    
I: HW Platform: Nordic Semiconductor (0x0002)
I: HW Variant: nRF54Lx (0x0005)
I: Firmware: Standard Bluetooth controller (0x00) Version 137.20634 Build 2617349514
I: Identity: C6:41:B0:37:C1:9F (random)
I: HCI: version 6.0 (0x0e) revision 0x30f3, manufacturer 0x0059
I: LMP: version 6.0 (0x0e) subver 0x30f3
I: Waiting for 2 reflector connections...
I: Filters matched. Address: F6:01:EA:F1:47:51 (random), Name: Reflector-1, connectable: 1 (current connections: 0/2)
I: Attempting to connect to F6:01:EA:F1:47:51 (random)
I: Connected to F6:01:EA:F1:47:51 (random) (err 0x00)
I: Stored connection for reflector 0
I: Continuing to scan for more reflectors (1/2 found)
I: Connected to reflector 0 (1/2 total)
I: Filters matched. Address: FF:E7:7D:64:BC:8B (random), Name: Reflector-2, connectable: 1 (current connections: 1/2)
I: Attempting to connect to FF:E7:7D:64:BC:8B (random)
I: Connected to FF:E7:7D:64:BC:8B (random) (err 0x00)
I: Stored connection for reflector 1
I: All reflectors found, stopping scan
I: Connected to reflector 1 (2/2 total)
I: Setup complete for 2 reflectors, starting ranging
I: Setting up reflector connection 0
I: Security changed: F6:01:EA:F1:47:51 (random) level 2
I: MTU exchange success (498)
I: The discovery procedure succeeded
I: CS capability exchange completed.
I: CS config creation complete. ID: 0
I: CS security enabled.
I: Reflector connection 0 setup complete
I: Setting up reflector connection 1
E: Failed to encrypt connection (err -12)
I: CS procedures enabled:
 - config ID: 0
 - antenna configuration index: 0
 - TX power: 0 dbm
 - subevent length: 28198 us
 - subevents per event: 1
 - subevent interval: 0
 - event interval: 2
 - procedure interval: 10
 - procedure count: 0
 - maximum procedure length: 1000
I: Sleeping for 1000 ms...
I: Sleeping for 1000 ms...
I: Sleeping for 1000 ms...
I: Ranging data overwritten 4
I: Sleeping for 1000 ms...
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.049362 (avg: 2.049362), phase_slope: 3.913533, rtt: 7.974549
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.561703 (avg: 2.305533), phase_slope: 3.693789, rtt: 8.000714
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.342128 (avg: 2.317731), phase_slope: 3.664881, rtt: 7.925765
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.383952 (avg: 2.334286), phase_slope: 3.921384, rtt: 7.724940
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Ranging data overwritten 17
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.383952 (avg: 2.344220), phase_slope: 3.861651, rtt: 7.836896
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.383952 (avg: 2.411137), phase_slope: 3.861651, rtt: 7.836896
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.268937 (avg: 2.352584), phase_slope: 3.997900, rtt: 7.880391
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.268937 (avg: 2.337946), phase_slope: 3.997900, rtt: 7.880391
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.268937 (avg: 2.314943), phase_slope: 3.997900, rtt: 7.880391
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Ranging data overwritten 27
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.179481 (avg: 2.274049), phase_slope: 4.024032, rtt: 7.867682
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.305533 (avg: 2.258365), phase_slope: 3.985970, rtt: 7.882163
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Ranging data overwritten 31
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.305533 (avg: 2.265684), phase_slope: 3.985970, rtt: 7.882163
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.216657 (avg: 2.255228), phase_slope: 4.044756, rtt: 7.828835
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Ranging data overwritten 35
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.098157 (avg: 2.221072), phase_slope: 4.178952, rtt: 7.812559
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.873703 (avg: 2.159916), phase_slope: 4.159396, rtt: 7.735431
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Ranging data overwritten 40
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.873703 (avg: 2.073550), phase_slope: 4.159396, rtt: 7.735431
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
I: Sleeping for 1000 ms...
I: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.049362 (avg: 2.022316), phase_slope: 4.244737, rtt: 7.811957
I: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000

Logs from reflector 1:

*** Booting nRF Connect SDK v3.0.2-89ba1294ac9b ***
*** Using Zephyr OS v4.0.99-f791c49f492c ***
I: Starting Channel Sounding Reflector Sample:  ================== Reflector-1 ================== 
I: SoftDevice Controller build revision: 
I: 89 9a 50 8a 95 01 9c 58 |..P....X
I: fc 39 d2 c1 10 04 ee 02 |.9......
I: 64 ce 25 be             |d.%.    
I: HW Platform: Nordic Semiconductor (0x0002)
I: HW Variant: nRF54Lx (0x0005)
I: Firmware: Standard Bluetooth controller (0x00) Version 137.20634 Build 2617349514
I: Identity: F6:01:EA:F1:47:51 (random)
I: HCI: version 6.0 (0x0e) revision 0x30f3, manufacturer 0x0059
I: LMP: version 6.0 (0x0e) subver 0x30f3
I: Connected to C6:41:B0:37:C1:9F (random) (err 0x00)
I: CS capability exchange completed.
I: CS config creation complete. ID: 0
I: CS security enabled.
I: CS procedures enabled.

Logs from reflector 2:

*** Booting nRF Connect SDK v3.0.2-89ba1294ac9b ***
*** Using Zephyr OS v4.0.99-f791c49f492c ***
I: Starting Channel Sounding Reflector Sample:  ================== Reflector-2 ================== 
I: SoftDevice Controller build revision: 
I: 89 9a 50 8a 95 01 9c 58 |..P....X
I: fc 39 d2 c1 10 04 ee 02 |.9......
I: 64 ce 25 be             |d.%.    
I: HW Platform: Nordic Semiconductor (0x0002)
I: HW Variant: nRF54Lx (0x0005)
I: Firmware: Standard Bluetooth controller (0x00) Version 137.20634 Build 2617349514
I: Identity: FF:E7:7D:64:BC:8B (random)
I: HCI: version 6.0 (0x0e) revision 0x30f3, manufacturer 0x0059
I: LMP: version 6.0 (0x0e) subver 0x30f3
I: Connected to C6:41:B0:37:C1:9F (random) (err 0x00)

You will notice that in reflector 2, the channel sounding logs are missing. And it's not always reflector 2, sometimes reflector 2 works and reflector 1 doesn't. Whichever connects first works.

Thanks for the help.

Regards,

Usman

[Edvin]

Hello Usman,

ranging_data_get_complete_cb(), does that ever trigger for the device that returns distance = 0?

Best regards,

Edvin

[usmanmehmood55]

Hi Edvin 

Sorry for the late reply. I printed the extra logs and it looks like ranging_data_get_complete_cb() is not triggering for the reflector returning 0.

*** Booting nRF Connect SDK v3.0.2-89ba1294ac9b ***
*** Using Zephyr OS v4.0.99-f791c49f492c ***
[00:00:00.008,853] <inf> app_main: Starting Channel Sounding Initiator Sample
[00:00:00.016,653] <inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
                                            89 9a 50 8a 95 01 9c 58  fc 39 d2 c1 10 04 ee 02 |..P....X .9......
                                            64 ce 25 be                                      |d.%.             
[00:00:00.046,083] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.054,020] <inf> bt_hci_core: HW Variant: nRF54Lx (0x0005)
[00:00:00.060,816] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 137.20634 Build 2617349514
[00:00:00.072,776] <inf> bt_hci_core: Identity: C6:41:B0:37:C1:9F (random)
[00:00:00.080,208] <inf> bt_hci_core: HCI: version 6.0 (0x0e) revision 0x30f3, manufacturer 0x0059
[00:00:00.089,748] <inf> bt_hci_core: LMP: version 6.0 (0x0e) subver 0x30f3
[00:00:00.097,904] <inf> app_main: Waiting for 2 reflector connections...
[00:00:00.118,260] <inf> app_main: Filters matched. Address: FF:E7:7D:64:BC:8B (random), Name: Reflector-2, connectable: 1 (current connections: 0/2)
[00:00:00.133,078] <inf> app_main: Attempting to connect to FF:E7:7D:64:BC:8B (random)
[00:00:00.226,570] <inf> app_main: Connected to FF:E7:7D:64:BC:8B (random) (err 0x00)
[00:00:00.235,124] <inf> app_main: Stored connection for reflector 0
[00:00:00.242,159] <inf> app_main: Continuing to scan for more reflectors (1/2 found)
[00:00:00.251,569] <inf> app_main: Connected to reflector 0 (1/2 total)
[00:00:00.661,267] <inf> app_main: Filters matched. Address: F6:01:EA:F1:47:51 (random), Name: Reflector-1, connectable: 1 (current connections: 1/2)
[00:00:00.676,037] <inf> app_main: Attempting to connect to F6:01:EA:F1:47:51 (random)
[00:00:00.769,638] <inf> app_main: Connected to F6:01:EA:F1:47:51 (random) (err 0x00)
[00:00:00.778,036] <inf> app_main: Stored connection for reflector 1
[00:00:00.785,108] <inf> app_main: All reflectors found, stopping scan
[00:00:00.792,741] <inf> app_main: Connected to reflector 1 (2/2 total)
[00:00:00.799,908] <inf> app_main: Setup complete for 2 reflectors, starting ranging
[00:00:00.808,246] <inf> app_main: Setting up reflector connection 0
[00:00:01.628,047] <inf> app_main: Security changed: FF:E7:7D:64:BC:8B (random) level 2
[00:00:01.728,026] <inf> app_main: MTU exchange success (498)
[00:00:02.128,032] <inf> app_main: The discovery procedure succeeded
[00:00:02.278,169] <inf> app_main: CS capability exchange completed.
[00:00:02.428,070] <inf> app_main: CS config creation complete. ID: 0
[00:00:02.628,029] <inf> app_main: CS security enabled.
[00:00:02.634,239] <inf> app_main: Reflector connection 0 setup complete
[00:00:02.641,644] <inf> app_main: Setting up reflector connection 1
[00:00:02.878,146] <inf> app_main: CS procedures enabled:
- config ID: 0
- antenna configuration index: 0
- TX power: 0 dbm
- subevent length: 28198 us
- subevents per event: 1
- subevent interval: 0
- event interval: 2
- procedure interval: 10
- procedure count: 0
- maximum procedure length: 1000
[00:00:03.328,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 0
[00:00:03.385,550] <inf> app_main: Security changed: F6:01:EA:F1:47:51 (random) level 2
[00:00:03.485,529] <inf> app_main: MTU exchange success (498)
[00:00:03.628,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 0 from reflector 0
[00:00:03.828,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 1
[00:00:03.885,535] <inf> app_main: The discovery procedure succeeded
[00:00:04.085,672] <inf> app_main: CS capability exchange completed.
[00:00:04.128,036] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 1 from reflector 0
[00:00:04.285,573] <inf> app_main: CS config creation complete. ID: 0
[00:00:04.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 2
[00:00:04.485,531] <inf> app_main: CS security enabled.
[00:00:04.491,621] <wrn> bt_hci_core: opcode 0x2094 status 0x07 
[00:00:04.498,188] <err> app_main: Failed to enable CS procedures (err -5)
[00:00:04.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 2 from reflector 0
[00:00:04.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 3
[00:00:05.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 3 from reflector 0
[00:00:05.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 4
[00:00:05.505,779] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.003325 (avg: 2.003325), phase_slope: 2.329631, rtt: 0.000000
[00:00:05.520,180] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:05.534,714] <inf> app_main: Sleeping for 1000 ms...
[00:00:05.724,374] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:05.735,838] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 4 from reflector 0
[00:00:05.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 5
[00:00:06.228,024] <inf> app_main: Ranging data overwritten 5
[00:00:06.328,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 6
[00:00:06.541,043] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.003325 (avg: 2.003325), phase_slope: 2.516117, rtt: 0.000000
[00:00:06.555,453] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:06.569,876] <inf> app_main: Sleeping for 1000 ms...
[00:00:06.678,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 6 from reflector 0
[00:00:06.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 7
[00:00:07.178,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 7 from reflector 0
[00:00:07.328,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 8
[00:00:07.576,084] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.895426 (avg: 1.967359), phase_slope: 2.641607, rtt: 0.000000
[00:00:07.590,986] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:07.605,402] <inf> app_main: Sleeping for 1000 ms...
[00:00:07.678,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 8 from reflector 0
[00:00:07.878,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 9
[00:00:08.178,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 9 from reflector 0
[00:00:08.328,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 10
[00:00:08.611,604] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.813937 (avg: 1.929003), phase_slope: 2.587863, rtt: 0.000000
[00:00:08.626,014]  <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 10 from reflector 0
[1;32m<inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:08.655,077] <inf> app_main: Sleeping for 1000 ms...
[00:00:08.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 11
[00:00:09.128,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 11 from reflector 0
[00:00:09.328,412] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 12
[00:00:09.661,301] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.626813 (avg: 1.868565), phase_slope: 2.730412, rtt: 0.000000
[00:00:09.675,705] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:09.690,352] <inf> app_main: Sleeping for 1000 ms...
[00:00:09.724,362] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:09.735,841] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 12 from reflector 0
[00:00:09.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 13
[00:00:10.228,025] <inf> app_main: Ranging data overwritten 13
[00:00:10.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 14
[00:00:10.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 14 from reflector 0
[00:00:10.696,565] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.624049 (avg: 1.792710), phase_slope: 2.836699, rtt: 0.000000
[00:00:10.711,517] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:10.727,319] <inf> app_main: Sleeping for 1000 ms...
[00:00:10.828,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 15
[00:00:11.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 15 from reflector 0
[00:00:11.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 16
[00:00:11.678,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 16 from reflector 0
[00:00:11.733,653] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.570854 (avg: 1.706216), phase_slope: 2.872743, rtt: 0.000000
[00:00:11.748,200] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:11.762,607] <inf> app_main: Sleeping for 1000 ms...
[00:00:11.828,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 17
[00:00:12.224,275] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:12.235,748] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 17 from reflector 0
[00:00:12.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 18
[00:00:12.728,024] <inf> app_main: Ranging data overwritten 18
[00:00:12.768,821] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.633772 (avg: 1.653885), phase_slope: 2.778327, rtt: 0.000000
[00:00:12.783,522] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:12.798,097] <inf> app_main: Sleeping for 1000 ms...
[00:00:12.878,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 19
[00:00:13.224,548] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:13.278,036] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 19 from reflector 0
[00:00:13.804,516] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.701904 (avg: 1.631479), phase_slope: 2.778607, rtt: 0.000000
[00:00:13.819,901] <inf> app_main: Reflector 1 - Distance estimates on antenna path [00:00:13.828,029] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 21
0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:13.842,562] <inf> app_main: Sleeping for 1000 ms...
[00:00:14.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 21 from reflector 0
[00:00:14.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 22
[00:00:14.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 22 from reflector 0
[00:00:14.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 23
[00:00:14.848,759] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.701904 (avg: 1.646497), phase_slope: 2.802526, rtt: 0.000000
[00:00:14.863,167] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:14.877,630] <inf> app_main: Sleeping for 1000 ms...
[00:00:15.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 23 from reflector 0
[00:00:15.328,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 24
[00:00:15.678,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 24 from reflector 0
[00:00:15.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 25
[00:00:15.884,213] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.832022 (avg: 1.688091), phase_slope: 2.726507, rtt: 0.000000
[00:00:15.898,809] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:15.913,224] <inf> app_main: Sleeping for 1000 ms...
[00:00:16.128,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 25 from reflector 0
[00:00:16.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 26
[00:00:16.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 26 from reflector 0
[00:00:16.878,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 27
[00:00:16.919,447] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.766963 (avg: 1.727313), phase_slope: 2.604568, rtt: 0.000000
[00:00:16.933,934] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:16.948,524] <inf> app_main: Sleeping for 1000 ms...
[00:00:17.178,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 27 from reflector 0
[00:00:17.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 28
[00:00:17.724,450] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:17.735,930] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 28 from reflector 0
[00:00:17.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 29
[00:00:17.954,741] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.766963 (avg: 1.753951), phase_slope: 2.604568, rtt: 0.000000
[00:00:17.969,141] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:17.983,719] <inf> app_main: Sleeping for 1000 ms...
[00:00:18.278,024] <inf> app_main: Ranging data overwritten 29
[00:00:18.428,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 30
[00:00:18.724,275] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:18.878,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 30 from reflector 0
[00:00:18.990,101] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.766963 (avg: 1.766963), phase_slope: 2.604568, rtt: 0.000000
[00:00:19.004,506] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:19.018,920] <inf> app_main: Sleeping for 1000 ms...
[00:00:19.478,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 32
[00:00:19.724,625] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:19.978,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 32 from reflector 0
[00:00:20.025,143] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.766963 (avg: 1.779975), phase_slope: 2.604568, rtt: 0.000000
[00:00:20.039,953] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:20.054,363] <inf> app_main: Sleeping for 1000 ms...
[00:00:20.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 34
[00:00:20.678,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 34 from reflector 0
[00:00:20.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 35
[00:00:21.060,565] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.736890 (avg: 1.760949), phase_slope: 2.587095, rtt: 0.000000
[00:00:21.074,982] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:21.090,610] <inf> app_main: Sleeping for 1000 ms...
[00:00:21.224,450] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:21.235,931] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 35 from reflector 0
[00:00:21.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 36
[00:00:21.728,025] <inf> app_main: Ranging data overwritten 36
[00:00:21.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 37
[00:00:22.096,821] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.779429 (avg: 1.763442), phase_slope: 2.625187, rtt: 0.000000
[00:00:22.111,226] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:22.125,644] 00:00:22.128,036] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 37 from reflector 0
2m<inf> app_main: Sleeping for 1000 ms...
[00:00:22.328,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 38
[00:00:22.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 38 from reflector 0
[00:00:22.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 39
[00:00:23.128,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 39 from reflector 0
[00:00:23.146,455] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.738612 (avg: 1.757771), phase_slope: 2.770703, rtt: 0.000000
[00:00:23.160,856] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:23.175,274] <inf> app_main: Sleeping for 1000 ms...
[00:00:23.328,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 40
[00:00:23.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 40 from reflector 0
[00:00:23.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 41
[00:00:24.128,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 41 from reflector 0
[00:00:24.181,813] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.797165 (avg: 1.763812), phase_slope: 2.887904, rtt: 0.000000
[00:00:24.196,397] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:24.211,343] <inf> app_main: Sleeping for 1000 ms...
[00:00:24.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 42
[00:00:24.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 42 from reflector 0
[00:00:24.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 43
[00:00:25.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 43 from reflector 0
[00:00:25.217,630] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.847561 (avg: 1.779931), phase_slope: 2.934223, rtt: 0.000000
[00:00:25.233,488] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:25.248,100] <inf> app_main: Sleeping for 1000 ms...
[00:00:25.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 44
[00:00:25.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 44 from reflector 0
[00:00:25.828,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 45
[00:00:26.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 45 from reflector 0
[00:00:26.254,325] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.906115 (avg: 1.813776), phase_slope: 3.203472, rtt: 0.000000
[00:00:26.268,733] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:26.283,407] <inf> app_main: Sleeping for 1000 ms...
[00:00:26.428,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 46
[00:00:26.724,635] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:26.828,036] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 46 from reflector 0
[00:00:27.289,781] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.894822 (avg: 1.836855), phase_slope: 3.298077, rtt: 0.000000
[00:00:27.304,478] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:27.319,769] <inf> app_main: Sleeping for 1000 ms...
[00:00:27.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 48
[00:00:27.678,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 48 from reflector 0
[00:00:27.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 49
[00:00:28.178,036] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 49 from reflector 0
[00:00:28.325,975] 00:00:28.328,028] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 50
1;32m<inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.980858 (avg: 1.885304), phase_slope: 3.248099, rtt: 0.000000
[00:00:28.348,575] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:28.362,986] <inf> app_main: Sleeping for 1000 ms...
[00:00:28.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 50 from reflector 0
[00:00:28.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 51
[00:00:29.128,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 51 from reflector 0
[00:00:29.328,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 52
[00:00:29.369,207] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.990888 (avg: 1.924049), phase_slope: 3.137689, rtt: 0.000000
[00:00:29.384,058] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:29.398,607] <inf> app_main: Sleeping for 1000 ms...
[00:00:29.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 52 from reflector 0
[00:00:29.878,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 53
[00:00:30.178,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 53 from reflector 0
[00:00:30.378,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 54
[00:00:30.404,823] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.020164 (avg: 1.958569), phase_slope: 3.274416, rtt: 0.000000
[00:00:30.419,230] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:30.434,119] <inf> app_main: Sleeping for 1000 ms...
[00:00:30.724,276] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:30.735,748] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 54 from reflector 0
[00:00:30.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 55
[00:00:31.228,025] <inf> app_main: Ranging data overwritten 55
[00:00:31.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 56
[00:00:31.440,469] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.969768 (avg: 1.971300), phase_slope: 3.263761, rtt: 0.000000
[00:00:31.454,871] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:31.469,286] <inf> app_main: Sleeping for 1000 ms...
[00:00:31.678,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 56 from reflector 0
[00:00:31.878,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 57
[00:00:32.178,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 57 from reflector 0
[00:00:32.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 58
[00:00:32.475,477] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.969768 (avg: 1.986289), phase_slope: 3.192044, rtt: 0.000000
[00:00:32.490,809] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:32.505,222] <inf> app_main: Sleeping for 1000 ms...
[00:00:32.628,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 58 from reflector 0
[00:00:32.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 59
[00:00:33.178,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 59 from reflector 0
[00:00:33.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 60
[00:00:33.511,445] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.940491 (avg: 1.978216), phase_slope: 3.137436, rtt: 0.000000
[00:00:33.525,848] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:33.541,388] <inf> app_main: Sleeping for 1000 ms...
[00:00:33.628,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 60 from reflector 0
[00:00:33.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 61
[00:00:34.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 61 from reflector 0
[00:00:34.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 62
[00:00:34.547,605] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.973975 (avg: 1.974833), phase_slope: 3.165542, rtt: 0.000000
[00:00:34.562,012] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:34.576,433] <inf> app_main: Sleeping for 1000 ms...
[00:00:34.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 62 from reflector 0
[00:00:34.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 63
[00:00:35.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 63 from reflector 0
[00:00:35.328,411] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 64
[00:00:35.583,093] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.876115 (avg: 1.946023), phase_slope: 3.266909, rtt: 0.000000
[00:00:35.597,695] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:35.612,113] <inf> app_main: Sleeping for 1000 ms...
[00:00:35.628,036] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 64 from reflector 0
[00:00:35.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 65
[00:00:36.178,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 65 from reflector 0
[00:00:36.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 66
[00:00:36.618,325] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 1.876115 ([00:00:36.628,037] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 66 from reflector 0
avg: 1.927293), phase_slope: 3.258581, rtt: 0.000000
[00:00:36.647,348] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:36.661,759] <inf> app_main: Sleeping for 1000 ms...
[00:00:36.828,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 67
[00:00:37.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 67 from reflector 0
[00:00:37.328,026] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 68
[00:00:37.628,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 68 from reflector 0
[00:00:37.667,959] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.004985 (avg: 1.934336), phase_slope: 3.175309, rtt: 0.000000
[00:00:37.682,665] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:37.697,230] <inf> app_main: Sleeping for 1000 ms...
[00:00:37.828,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 69
[00:00:38.128,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 69 from reflector 0
[00:00:38.428,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 70
[00:00:38.703,808] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.004985 (avg: 1.947235), phase_slope: 3.175362, rtt: 0.000000
[00:00:38.718,371] <inf> app_main: Reflector 1 -[00:00:38.724,277] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
 Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:38.745,227] <inf> app_main: Sleeping for 1000 ms...
[00:00:38.928,035] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 70 from reflector 0
[00:00:39.528,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 72
[00:00:39.724,538] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:39.751,446] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.004985 (avg: 1.953437), phase_slope: 3.175362, rtt: 0.000000
[00:00:39.765,860] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:39.780,453] <inf> app_main: Sleeping for 1000 ms...
[00:00:40.224,188] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:40.428,034] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 72 from reflector 0
[00:00:40.786,805] <inf> app_main: Reflector 0 - Distance estimates on antenna path 0: ifft: 2.004985 (avg: 1.979211), phase_slope: 3.175362, rtt: 0.000000
[00:00:40.801,449] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:40.816,761] <inf> app_main: Sleeping for 1000 ms...
[00:00:40.928,025] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 75
[00:00:41.224,450] <dbg> app_main: subevent_result_cb: Dropped subevent results due to unfinished ranging data request.
[00:00:41.278,036] <dbg> app_main: ranging_data_get_complete_cb: Ranging data get completed for ranging counter 75 from reflector 0
[00:00:41.822,967] <inf> app_main: Reflector 0 - [00:00:41.828,027] <dbg> app_main: ranging_data_ready_cb: Ranging data ready 77
Distance estimates on antenna path 0: ifft: 2.004985 (avg: 2.004985), phase_slope: 3.175362, rtt: 0.000000
[00:00:41.845,601] <inf> app_main: Reflector 1 - Distance estimates on antenna path 0: ifft: 0.000000 (avg: 0.000000), phase_slope: 0.000000, rtt: 0.000000
[00:00:41.860,016] <inf> app_main: Sleeping for 1000 ms...

But it's not even initiating channel sounding with the second reflector. Only one of the reflectors initiates channel sounding. Is this an SDK limitation?

Regards,

Usman

[Edvin]

See if it reacts the same in NCS v3.1.0. There were some issues with multiple connections and channel sounding in NCS v3.0.2.

Best regards,

Edvin