This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

GATT TIMEOUT ERROR when moving away quickly from the device

Hello everyone,

I am having an odd problem. I am using an SoC based on the nRF52832 (the ISP1507-AX). I am using ncs v1.7.0 for development. I am trying out a few things and right now, I have a sensor that needs to advertise every 50ms. I've noticed a strange bug however. When connected to the device and moving away quickly from it, a GATT TIMEOUT ERROR (0x08) happens. The sensor/device seems to reboot completely.

  I have no idea where it comes from, I did change the peripheral preferred max/min connection interval to be around half of 50ms but this error still happens. 

Would anyone have any idea about what is going on ?

Attached you'll find all files.timeout_range_pblm.zip

Here is the main.c:

/* Standard and Zephyr libraries */
#include <zephyr.h>
#include <stdio.h>
#include <stddef.h>
#include <string.h>
#include <errno.h>
#include <soc.h>
#include <sys/byteorder.h>
#include <sys/util.h>
#include <device.h>
#include <devicetree.h>
#include <drivers/sensor.h>

/* Bluetooth Stack Libraries */
#include <bluetooth/bluetooth.h>
#include <bluetooth/hci.h>
#include <bluetooth/conn.h>
#include <bluetooth/uuid.h>
#include <bluetooth/gatt.h>
#include <bluetooth/services/bas.h>
#include <bluetooth/services/dis.h>
#include <bluetooth/services/hrs.h>

/* Settings librairy for DIS */
#include <settings/settings.h>

/* Logging module */
#include <logging/log.h>
LOG_MODULE_REGISTER(main, LOG_LEVEL_INF);

/**************************************************************************
 * DECLARATIONS
 *************************************************************************/

void sensor_stop(void);
void sensor_start(void);

/**************************************************************************
 * BLUETOOTH FUNCTIONS
 *************************************************************************/

/** Device Name as defined in the prj.conf */
#define DEVICE_NAME CONFIG_BT_DEVICE_NAME
/** device name length */
#define DEVICE_NAME_LEN (sizeof(DEVICE_NAME) - 1)

static const struct bt_data ad[] = {
	BT_DATA_BYTES(BT_DATA_FLAGS, (BT_LE_AD_GENERAL | BT_LE_AD_NO_BREDR)),
	BT_DATA_BYTES(BT_DATA_UUID16_ALL,
		      BT_UUID_16_ENCODE(BT_UUID_HRS_VAL),
		      BT_UUID_16_ENCODE(BT_UUID_BAS_VAL),
		      BT_UUID_16_ENCODE(BT_UUID_DIS_VAL))
};

static void connected(struct bt_conn *conn, uint8_t err)
{
	if (err) {
		LOG_ERR("Connection failed (err 0x%02x)", err);
	} else {
		LOG_INF("Connected\n");
        sensor_start();
	}
}

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

static struct bt_conn_cb conn_callbacks = {
	.connected = connected,
	.disconnected = disconnected,
};

static void bt_ready(void)
{
	int err;

	LOG_INF("Bluetooth initialized");

	err = bt_le_adv_start(BT_LE_ADV_CONN_NAME, ad, ARRAY_SIZE(ad), NULL, 0);
	if (err) {
		LOG_ERR("Advertising failed to start (err %d)", err);
		return;
	}

	LOG_INF("Advertising successfully started");
}

static void bas_notify(void)
{
	uint8_t battery_level = bt_bas_get_battery_level();

	battery_level--;

	if (!battery_level) {
		battery_level = 100U;
	}

	bt_bas_set_battery_level(battery_level);
}

static void hrs_notify(uint8_t heartrate)
{
	bt_hrs_notify(heartrate);
}

static void ble_init(void)
{
    int err;

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

	bt_ready();

	bt_conn_cb_register(&conn_callbacks);
}

/**************************************************************************
 * UPDATE VALUES FUNCTIONS
 *************************************************************************/

#define START_DELAY_MS              5000
#define SENSOR_SAMPLING_TIME_MS     50

static K_SEM_DEFINE(sensor_ok, 0, 1);
static K_SEM_DEFINE(sensor_init_ok, 0, 1);

static void sensor_timer_handler(struct k_timer *dummy)
{
    k_sem_give(&sensor_ok);
}

K_TIMER_DEFINE(sensor_timer, sensor_timer_handler, NULL);

int sensor_init(void)
{
    int status = 0;

    /* Indicate to the processing thread that initialization is finished */
    k_sem_give(&sensor_init_ok);

    return status;
}

void sensor_stop(void)
{
    k_timer_stop(&sensor_timer);
    LOG_INF("Sensor stopped.\n");
}

void sensor_start(void)
{
    /* start periodic timer that expires once every "samplingTime" */
    k_timer_start(&sensor_timer, K_MSEC(START_DELAY_MS),
                  K_MSEC(SENSOR_SAMPLING_TIME_MS));
    LOG_INF("Sensor started.\n");
}

void sensor_process_thread(void)
{
    /* Wait for the sensor to be initialized before starting the thread loop. */
    k_sem_take(&sensor_init_ok, K_FOREVER);

    static uint8_t sensor_data = 90;

    while (1)
    {
        /* Semaphore is available every sampling time */
        k_sem_take(&sensor_ok, K_FOREVER);

        /* Notify new sensor value */
	    sensor_data++;
	    if (sensor_data == 160U) {
		    sensor_data = 90U;
	    }
        hrs_notify(sensor_data);
    }
}

/* Defines the processor thread with its stacksize and priority. */
K_THREAD_DEFINE(sensor_producer_thread_id, 1024,
                sensor_process_thread, NULL, NULL,
                NULL, 5, 0, 0);

/**************************************************************************
 * MAIN
 *************************************************************************/

void main(void)
{
    sensor_init();
    ble_init();

    while(1)
    {
        bas_notify();
        k_sleep(K_MSEC(5000));
    }
}

Here is the prj.conf:

# Deactivate DEBUG/LOG for production builds
CONFIG_DEBUG=y
CONFIG_SERIAL=y
# Logging
CONFIG_LOG=y

# segger RTT console
CONFIG_USE_SEGGER_RTT=y
CONFIG_RTT_CONSOLE=y
CONFIG_UART_CONSOLE=n

# Unused Peripherals
CONFIG_SPI=n

# Activate the BLE layer, set as peripheral
CONFIG_BT=y
CONFIG_BT_DEBUG_LOG=y
CONFIG_BT_DEBUG_SERVICE=y
CONFIG_BT_SMP=y
CONFIG_BT_PERIPHERAL=y
CONFIG_BT_CTLR=y
CONFIG_BT_CTLR_PHY_2M=y
CONFIG_BT_GATT_CLIENT=y
# Set up the Services
CONFIG_BT_DIS=y
CONFIG_BT_DIS_PNP=n
CONFIG_BT_BAS=y
CONFIG_BT_HRS=y

# Decrease connection interval to accomodate 50ms Respiration sampling rate
# Min = 17.5ms, Max = 22.5ms
CONFIG_BT_PERIPHERAL_PREF_MIN_INT=14
CONFIG_BT_PERIPHERAL_PREF_MAX_INT=18

# Set up device appearance
# Appearance 833 is Heart Rate Belt
CONFIG_BT_DEVICE_APPEARANCE=833

Here is the CMakeLists.txt:

# SPDX-License-Identifier: Apache-2.0

cmake_minimum_required(VERSION 3.13.1)

find_package(Zephyr REQUIRED HINTS $ENV{ZEPHYR_BASE})
project(peripheral_hr)

FILE(GLOB app_sources src/*.c)
target_sources(app PRIVATE
  ${app_sources}
  )

zephyr_library_include_directories(${ZEPHYR_BASE}/samples/bluetooth)

Thank you very much in advance for any help.

Best regards,

Parents
  • Hi,

    I assume you get the GATT TIMEOUT ERROR on an Android device? Have you doen any debugging to see what happens on the nRF? You write that it seems to reboot completely. It would be interesting to start by looking at the log and see what that gives you?

    Without knowing more than that this happens more when distance is increasing, I would think about things that would be affected by packet loss (for instance buffer filling up if you try to notify data faster than it is actually successfully transmitted).

Reply
  • Hi,

    I assume you get the GATT TIMEOUT ERROR on an Android device? Have you doen any debugging to see what happens on the nRF? You write that it seems to reboot completely. It would be interesting to start by looking at the log and see what that gives you?

    Without knowing more than that this happens more when distance is increasing, I would think about things that would be affected by packet loss (for instance buffer filling up if you try to notify data faster than it is actually successfully transmitted).

Children
  • That is what I am trying to do now. However, for no apparent reason (code is the exact same) the problem just disappeared. It was very consistent a few hours ago and without any change, it just stopped.

    If I can get it to occur again, I'll log with some CONFIG_BT_DEBUG_xxx activated.

  • Quick update:

    If I try to log something and/or add some CONFIG_BT_DEBUG_xxx (like CONN and L2CAP for example) the bug disappear. But if I am not connected through RTT viewer and do not have more than CONFIG_BT_DEBUG_SERVICE and CONFIG_BT_DEBUG_LOG activated, the bug happens.

    Would you happen to have any other idea on what I could do now ?

    Thank you for your time.

  • I did manage to log this:

    00> [00:00:28.585,479] <dbg> bt_hci_core.hci_tx_thread: Calling k_poll with 3 events
    00> [00:00:28.629,028] <dbg> sdc_hci_driver.event_packet_process: Event (0x13) len 5
    00> [00:00:28.629,058] <dbg> bt_hci_core.bt_recv: buf 0x20006b08 len 7
    00> [00:00:28.629,089] <dbg> bt_hci_core.hci_num_completed_packets: num_handles 1
    00> [00:00:28.629,089] <dbg> bt_hci_core.hci_num_completed_packets: handle 0 count 1
    00> [00:00:28.635,314] <dbg> bt_gatt.gatt_notify: conn 0x200016f0 handle 0x001b
    00> [00:00:28.635,345] <dbg> bt_l2cap.bt_l2cap_send_cb: conn 0x200016f0 cid 4 len 5
    00> [00:00:28.635,375] <dbg> bt_hci_core.process_events: count 3
    00> [00:00:28.635,375] <dbg> bt_hci_core.process_events: ev->state 0
    00> [00:00:28.635,375] <dbg> bt_hci_core.process_events: ev->state 0
    00> [00:00:28.635,406] <dbg> bt_hci_core.process_events: ev->state 4
    00> [00:00:28.635,437] <dbg> bt_hci_core.bt_send: buf 0x20007080 len 13 type 2
    00> [00:00:28.635,437] <dbg> sdc_hci_driver.hci_driver_send: 
    00> [00:00:28.635,437] <dbg> sdc_hci_driver.acl_handle: 
    00> [00:00:28.635,467] <dbg> sdc_hci_driver.hci_driver_send: Exit: 0
    00> [00:00:28.635,498] <dbg> bt_hci_core.hci_tx_thread: Calling k_poll with 3 events
    00> [00:00:28.674,041] <dbg> sdc_hci_driver.event_packet_process: Event (0x13) len 5
    00> [00:00:28.674,072] <dbg> bt_hci_core.bt_recv: buf 0x20006b08 len 7
    00> [00:00:28.674,072] <dbg> bt_hci_core.hci_num_completed_packets: num_handles 1
    00> [00:00:28.674,072] <dbg> bt_hci_core.hci_num_completed_packets: handle 0 count 1
    00> [00:00:28.685,333] <dbg> bt_gatt.gatt_notify: conn 0x200016f0 handle 0x001b
    00> [00:00:28.685,363] <dbg> bt_l2cap.bt_l2cap_send_cb: conn 0x200016f0 cid 4 len 5
    00> [00:00:28.685,394] <dbg> bt_hci_core.process_events: count 3
    00> [00:00:28.685,394] <dbg> bt_hci_core.process_events: ev->state 0
    00> [00:00:28.685,394] <dbg> bt_hci_core.process_events: ev->state 0
    00> [00:00:28.685,424] <dbg> bt_hci_core.process_events: ev->state 4
    00> [00:00:28.685,455] <dbg> bt_hci_core.bt_send: buf 0x20007080 len 13 type 2
    00> [00:00:28.685,455] <dbg> sdc_hci_driver.hci_driver_send: 
    00> [00:00:28.685,455] <dbg> sdc_hci_driver.acl_handle: 
    00> [00:00:28.685,485] <dbg> sdc_hci_driver.hci_driver_send: Exit: 0
    00> [00:00:28.685,516] <dbg> bt_hci_core.hci_tx_thread: Calling k_poll with 3 events

    The timeout occured at the last line and the device rebooted.

    This is the debug config I used:

    CONFIG_BT_DEBUG_LOG=y
    CONFIG_BT_DEBUG_SERVICE=y
    CONFIG_BT_DEBUG_L2CAP=y
    CONFIG_BT_DEBUG_GATT=y
    CONFIG_BT_DEBUG_HCI_CORE=y
    CONFIG_BT_DEBUG_HCI_DRIVER=y

  • It is interesting that logging seems to affect the issue. Perhaps there is something timing dependent here, a race condition or similar. It is not easy to see what that could be, though. I do not see any indication of an issue in the log. Can you post the full log (if it shows anything before or after this)? Is it possible to log anything from right before the reset (like a bus fault or something else), or is this all you can get while still triggering the issue?

    If it continue to be difficult to get useful information from debugging, perhaps it would also be sensible to adjust a few things that could have an impact. For instance, does it seem to help to increase the stack depths of the threads you have, for instance?

    Also, can you confirm that there is a clear connection between the issue and the increasing distance between the peers like you stated initially, or is that not clear?

  • I have continued to test a few things and have a few observations regarding your questions.

    The full log does not show anything of note, because the device reboots. And before the bug happens it is just the same messages again and again.

    I tried adjusting:

    ATT_PREPARE_COUNT, L2CAP_TX_BUF_COUNT, BUF_CMD_TX_COUNT, BUF_EVT_DISCARDABLE_COUNT, PERIPHERAL_PREF_TIMEOUT. I also changed priority and stack sizes of the threads I have and to no avail.

    After a few test and changes, I am not sure the distance has a connection with it. Sometimes I get away from the device and it immediately timeout. Sometimes it only disconnect when I come back near the device and after a few seconds.

Related