Multi reflector channel sounding

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

Parents
  • 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

  •   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

  • Hello Usman,

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

    Best regards,

    Edvin

  • Hi  

    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

Reply
  • Hi  

    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

Children
Related