espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.51k stars 7.26k forks source link

gatt_security_server Example: Added services are displayed twice at nrfConnect App (IDFGH-1130) #3446

Closed secureschwob closed 5 years ago

secureschwob commented 5 years ago

Environment

Problem Description

I extended the gatt_security_server example provided by esp-idf with additional services, namely the Battery Level Service and the Environmental Sensing Service. In order to do so, I followed the tutorials provided in the example folder and copied the lines of code used to create the Heart Rate Service in the original example. I played around with any combination of HRS, Battery Level and ESS and then connect to the ESP32 using the nrfConnect Android and Linux apps. As soon as I have created more than one GATT service at the ESP32, I see every service created twice (see screenshot. Let's number the services 1 to 4 beginning from the topmost Battery Service). I can read the characteristics of services 1 to 4 to get the dummy values written into the source code. However, only reading services 3 and 4 (i.e. the Battery Service and the Environmental Sensing Service displayed at the bottom of the screenshot) trigger an event in the debug logs on the monitor (e.g. V (1491156) HWS_SENSOR: event = 1).

nrf

An additional observation: Not only are the services shown twice, each characteristic within a service is also shown twice (please see the screenshot).

nrf2

Removing everything related to the Environmental Sensing Service, thus the Battery Sensing Service being the only service present, also removes the duplicate characteristics:

nrf3

Stepping through my Sourcecode with GDB shows, that the debug log messages

E (1076) BT_GATT: Active Service Found 
E (1076) BT_GATT: Duplicate Service start - Service already started

appear directly after having stepped over line 56 of the following GDB log:

739         ret = esp_ble_gatts_app_register(ESP_BATTERY_APP_ID);
(gdb) s
Target halted. PRO_CPU: PC=0x400EFF42 (active)    APP_CPU: PC=0x4014C44A 
esp_ble_gatts_app_register (app_id=87)
    at /opt/esp32_Development/esp-idf/components/bt/bluedroid/api/esp_gatts_api.c:44
44          ESP_BLUEDROID_STATUS_CHECK(ESP_BLUEDROID_STATUS_ENABLED);
(gdb) l
39      esp_err_t esp_ble_gatts_app_register(uint16_t app_id)
40      {
41          btc_msg_t msg;
42          btc_ble_gatts_args_t arg;
43
44          ESP_BLUEDROID_STATUS_CHECK(ESP_BLUEDROID_STATUS_ENABLED);
45          
46          //if (app_id < ESP_APP_ID_MIN || app_id > ESP_APP_ID_MAX) {
47          if (app_id > ESP_APP_ID_MAX) {
48              return ESP_ERR_INVALID_ARG;
(gdb) s
Target halted. PRO_CPU: PC=0x400EFD6F (active)    APP_CPU: PC=0x4014C44A 
esp_bluedroid_get_status ()
    at /opt/esp32_Development/esp-idf/components/bt/bluedroid/api/esp_bt_main.c:28
28          if (bd_already_init) {
(gdb) n
29              if (bd_already_enable) {
(gdb) n
30                  return ESP_BLUEDROID_STATUS_ENABLED;
(gdb) n
esp_ble_gatts_app_register(app_id=85)
    at /opt/esp32_Development/esp-idf/components/bt/bluedroid/api/esp_gatts_api.c:47
47          if (app_id > ESP_APP_ID_MAX) {
(gdb) n
51          msg.sig = BTC_SIG_API_CALL;
(gdb) n
52          msg.pid = BTC_PID_GATTS;
(gdb) n
53          msg.act = BTC_GATTS_ACT_APP_REGISTER;
(gdb) n
54          arg.app_reg.app_id = app_id;
(gdb) n
#stepping over this line prints "Active Service Found" message shown above
56          return (btc_transfer_context(&msg, &arg, sizeof(btc_ble_gatts_args_t), NULL) == BT_STATUS_SUCCESS ? ESP_OK : ESP_FAIL); 

Trying to step into btc_transfer_context causes my debugger to stop, thus I could not dig deeper.

Am I mistaken about how to add services?

Expected Behavior

Every service created should be visible only once.

Actual Behavior

Every service created is shown twice.

Steps to reproduce

  1. Add the code snippets posted below to the gatt_security_server example provided by esp-idf
  2. use the nrfConnect or similar app to connect to the ESP32 and discover services

Code to reproduce this issue

Please see relevant snippets at https://gist.github.com/secureschwob/8e829e909a695b1338f269e07950c618.

Debug Logs

I (606) phy: phy_version: 4100, 2a5dd04, Jan 23 2019, 21:00:07, 0, 0
I (846) HWS_SENSOR: app_main init bluetooth
D (846) nvs: nvs_open_from_partition bt_config.conf 1
D (846) nvs: nvs_get_str_or_blob bt_cfg_key0
D (846) nvs: nvs_get_str_or_blob bt_cfg_key0
D (856) nvs: nvs_close 2
D (856) nvs: nvs_open_from_partition bt_config.conf 1
D (866) nvs: nvs_set_blob bt_cfg_key0 475
D (876) nvs: nvs_close 3
V (996) HWS_SENSOR: event = 0

V (1006) HWS_SENSOR: event = 0

V (1006) HWS_SENSOR: event = 16

I (1006) HWS_SENSOR: The number handle = 3
V (1016) HWS_SENSOR: event = 16

I (1016) HWS_SENSOR: The number handle = 3
V (1016) HWS_SENSOR: event = 16

I (1026) HWS_SENSOR: The number handle = 3
V (1026) HWS_SENSOR: event = 16

I (1026) HWS_SENSOR: The number handle = 3
V (1046) HWS_SENSOR: event = 16

I (1046) HWS_SENSOR: The number handle = 3
V (1046) HWS_SENSOR: event = 16

I (1046) HWS_SENSOR: The number handle = 3
V (1056) HWS_SENSOR: event = 16

I (1056) HWS_SENSOR: The number handle = 3
V (1056) HWS_SENSOR: event = 16

I (1066) HWS_SENSOR: The number handle = 3
V (1066) HWS_SENSOR: GAP_EVT, event 22

E (1076) BT_GATT: Active Service Found 
E (1076) BT_GATT: Duplicate Service start - Service already started
E (1086) BT_GATT: Active Service Found 
E (1086) BT_GATT: Duplicate Service start - Service already started
E (1096) BT_GATT: Active Service Found 
E (1096) BT_GATT: Duplicate Service start - Service already started
V (1106) HWS_SENSOR: GAP_EVT, event 22

E (1106) BT_GATT: Active Service Found 
E (1116) BT_GATT: Duplicate Service start - Service already started
E (1116) BT_GATT: Active Service Found 
E (1126) BT_GATT: Duplicate Service start - Service already started
E (1136) BT_GATT: Active Service Found 
E (1136) BT_GATT: Duplicate Service start - Service already started
V (1146) HWS_SENSOR: event = c

V (1146) HWS_SENSOR: event = c

V (1146) HWS_SENSOR: event = c

V (1156) HWS_SENSOR: event = c

V (1156) HWS_SENSOR: event = c

V (1156) HWS_SENSOR: event = c

V (1166) HWS_SENSOR: event = c

V (1166) HWS_SENSOR: event = c

V (1166) HWS_SENSOR: event = c

V (1176) HWS_SENSOR: event = c

V (1176) HWS_SENSOR: event = c

V (1186) HWS_SENSOR: event = c

V (1186) HWS_SENSOR: event = c

V (1186) HWS_SENSOR: event = c

V (1186) HWS_SENSOR: event = c

V (1196) HWS_SENSOR: event = c

V (1196) HWS_SENSOR: GAP_EVT, event 0

V (1196) HWS_SENSOR: GAP_EVT, event 1

V (1206) HWS_SENSOR: GAP_EVT, event 0

V (1206) HWS_SENSOR: GAP_EVT, event 1

V (1226) HWS_SENSOR: GAP_EVT, event 6

I (1226) HWS_SENSOR: advertising start success
V (1236) HWS_SENSOR: GAP_EVT, event 6

I (1236) HWS_SENSOR: advertising start success
V (1246) HWS_SENSOR: GAP_EVT, event 6

I (1246) HWS_SENSOR: advertising start success
V (1246) HWS_SENSOR: event = 0

V (1246) HWS_SENSOR: event = 0

E (1256) BT_BTM: Advertising or scaning now, can't set privacy 
V (1266) HWS_SENSOR: event = 16

I (1266) HWS_SENSOR: The number handle = 3
V (1266) HWS_SENSOR: event = 16

I (1266) HWS_SENSOR: The number handle = 3
V (1276) HWS_SENSOR: event = 16

I (1276) HWS_SENSOR: The number handle = 3
V (1286) HWS_SENSOR: event = 16

I (1286) HWS_SENSOR: The number handle = 3
E (1296) BT_BTM: Advertising or scaning now, can't set privacy 
V (1306) HWS_SENSOR: event = 16

I (1306) HWS_SENSOR: The number handle = 3
V (1306) HWS_SENSOR: event = 16

I (1306) HWS_SENSOR: The number handle = 3
V (1316) HWS_SENSOR: event = 16

I (1316) HWS_SENSOR: The number handle = 3
V (1326) HWS_SENSOR: event = 16

I (1326) HWS_SENSOR: The number handle = 3
V (1326) HWS_SENSOR: GAP_EVT, event 22

E (1336) HWS_SENSOR: config local privacy failed, error status = 1
E (1346) BT_GATT: Active Service Found 
E (1346) BT_GATT: Duplicate Service start - Service already started
E (1356) BT_GATT: Active Service Found 
E (1356) BT_GATT: Duplicate Service start - Service already started
V (1366) HWS_SENSOR: GAP_EVT, event 22

E (1366) HWS_SENSOR: config local privacy failed, error status = 1
E (1376) BT_GATT: Active Service Found 
E (1376) BT_GATT: Duplicate Service start - Service already started
E (1386) BT_GATT: Active Service Found 
E (1396) BT_GATT: Duplicate Service start - Service already started
E (1396) BT_GATT: Active Service Found 
E (1406) BT_GATT: Duplicate Service start - Service already started
E (1406) BT_GATT: Active Service Found 
E (1416) BT_GATT: Duplicate Service start - Service already started
V (1426) HWS_SENSOR: event = c

V (1426) HWS_SENSOR: event = c

V (1426) HWS_SENSOR: event = c

V (1436) HWS_SENSOR: event = c

V (1436) HWS_SENSOR: event = c

V (1436) HWS_SENSOR: event = c

V (1446) HWS_SENSOR: event = c

V (1446) HWS_SENSOR: event = c

V (1446) HWS_SENSOR: event = c

V (1456) HWS_SENSOR: event = c

V (1456) HWS_SENSOR: event = c

V (1456) HWS_SENSOR: event = c

V (1456) HWS_SENSOR: event = c

V (1466) HWS_SENSOR: event = c

V (1466) HWS_SENSOR: event = c

V (1466) HWS_SENSOR: event = c
Weijian-Espressif commented 5 years ago

@secureschwob, Can you provide your test code?

secureschwob commented 5 years ago

Dear @Weijian-Espressif , thanks for your fast response. All lines of code, which modified the original esp-idf/examples/bluetooth/gatt_security_server/ example can be found at https://gist.github.com/secureschwob/8e829e909a695b1338f269e07950c618 . Are you missing something particular?

Weijian-Espressif commented 5 years ago

@secureschwob, Sorry I can not open the URL, probably because of China's firewall. Can you send an attachment?

secureschwob commented 5 years ago

@Weijian-Espressif Please find the source code from the Gist below:

/* File: example_ble_sec_gatts_demo.h */

// Battery Service
enum {
    BS_IDX_SVC,

    BS_IDX_MEAS_CHAR,
    BS_IDX_MEAS_VAL,

    BS_IDX_NB,
};

// Environmental Sensing Service (ESS) (partly implemented)
enum {
    ESS_IDX_SVC,            // ESS service index

    ESS_IDX_ES_TEMP_MEAS_CHAR,   // Characteristic index
    ESS_IDX_ES_TEMP_MEAS_VAL,    // Characteristic value index
     ESS_IDX_ES_MEAS_NTF_CFG,     ESS notifications configuration index

    ESS_IDX_NB,             // number of table elements
};

/* File: example_ble_sec_gatts_demo.c */
#include "example_ble_sec_gatts_demo.h"
#include "environmental_sensing_service.h"  #includes UUIDs of the service not found in 

#define PROFILE_NUM                 2

#define BATTERY_PROFILE_APP_IDX         0
#define ESP_BATTERY_APP_ID              0x57    //arbitrarily chosen
#define BATTERY_SVC_INST_ID             0
static uint16_t battery_service_handle_table[BS_IDX_NB];

#define ESS_PROFILE_APP_IDX         1
#define ESP_ESS_APP_ID              0x75    //arbitrarily chosen
#define ESS_SVC_INST_ID             0
static uint16_t ess_handle_table[ESS_IDX_NB];

static struct gatts_profile_inst profile_tab[PROFILE_NUM] = {
        [BATTERY_PROFILE_APP_IDX] = {
            .gatts_cb = gatts_profile_event_handler,    //TODO set another event handler?
            .gatts_if = ESP_GATT_IF_NONE,
        },
    [ESS_PROFILE_APP_IDX] = {
        .gatts_cb = gatts_profile_event_handler, //TODO set another event handler?
        .gatts_if = ESP_GATT_IF_NONE,
    },
};

/*Environmental Sensing PROFILE ATTRIBUTES */
// Environmental Sensing Service
static const uint16_t ess_svc = ESS_UUID_SERVICE;   //0x181A

/// ESS Characteristic
static const uint16_t temperature_uuid = ESS_UUID_TEMP_CHAR;    //0x2A6E
static const uint8_t temperature_value[1] = {0x0A};

static const esp_gatts_attr_db_t ess_gatt_db[ESS_IDX_NB] = {
    // Environmental Sensing Service Declaration
    [ESS_IDX_SVC]                    =
    {{ESP_GATT_AUTO_RSP}, {ESP_UUID_LEN_16, (uint8_t *)&primary_service_uuid, ESP_GATT_PERM_READ,
      sizeof(uint16_t), sizeof(ess_svc), (uint8_t *)&ess_svc}},

    // Battery Service Characteristic Declaration - wenn ich das auskommentiere sehe ich nur einen Leeren Battery Service mit dem ich nichts machen kann
    [ESS_IDX_ES_TEMP_MEAS_CHAR]  =
    {{ESP_GATT_AUTO_RSP}, {ESP_UUID_LEN_16, (uint8_t *)&character_declaration_uuid, ESP_GATT_PERM_READ,
      CHAR_DECLARATION_SIZE, CHAR_DECLARATION_SIZE, (uint8_t *)&char_prop_read}},

    // Battery Service Characteristic Value - wenn ich das auskommentiere sehe ich den Battery Service nicht
    [ESS_IDX_ES_TEMP_MEAS_VAL]   =
    {{ESP_GATT_AUTO_RSP}, {ESP_UUID_LEN_16, (uint8_t *)&temperature_uuid, ESP_GATT_PERM_READ_ENCRYPTED,
      sizeof(uint8_t), sizeof(temperature_value), (uint8_t *)temperature_value}},
};
#endif

/* Battery Service PROFILE ATRIBUTES */
/// Battery Service
static const uint16_t battery_svc = ESP_GATT_UUID_BATTERY_SERVICE_SVC;

/// Battery Level Characteristic
static const uint16_t battery_level_uuid = ESP_GATT_UUID_BATTERY_LEVEL;
static const uint8_t battery_level_value[1] = {0x60};

/// Full Battery Level Service Database Description - Used to add attributes into the database
static const esp_gatts_attr_db_t battery_level_gatt_db[BS_IDX_NB] = {
     // Battery Level Service Declaration - ohne den sehe ich in der Nordic App den Service nicht, HeartRate jedoch immer noch doppelt :D
    [BS_IDX_SVC]                    =
    {{ESP_GATT_AUTO_RSP}, {ESP_UUID_LEN_16, (uint8_t *)&primary_service_uuid, ESP_GATT_PERM_READ,
      sizeof(uint16_t), sizeof(battery_svc), (uint8_t *)&battery_svc}},

    // Battery Service Characteristic Declaration - wenn ich das auskommentiere sehe ich nur einen Leeren Battery Service mit dem ich nichts machen kann
    [BS_IDX_MEAS_CHAR]  =
    {{ESP_GATT_AUTO_RSP}, {ESP_UUID_LEN_16, (uint8_t *)&character_declaration_uuid, ESP_GATT_PERM_READ,
      CHAR_DECLARATION_SIZE, CHAR_DECLARATION_SIZE, (uint8_t *)&char_prop_read}},

    // Battery Service Characteristic Value - wenn ich das auskommentiere sehe ich den Battery Service nicht
    [BS_IDX_MEAS_VAL]   =
    {{ESP_GATT_AUTO_RSP}, {ESP_UUID_LEN_16, (uint8_t *)&battery_level_uuid, ESP_GATT_PERM_READ_ENCRYPTED,
      sizeof(uint8_t), sizeof(battery_level_value), (uint8_t *)battery_level_value}},
};

static void gatts_profile_event_handler(esp_gatts_cb_event_t event, esp_gatt_if_t gatts_if, esp_ble_gatts_cb_param_t *param)
{
    ESP_LOGV(GATTS_TABLE_TAG, "event = %x\n",event);
    switch (event) {
        case ESP_GATTS_REG_EVT:
            esp_ble_gap_set_device_name(EXCAMPLE_DEVICE_NAME);
            //generate a resolvable random address
            esp_ble_gap_config_local_privacy(true);

            esp_ble_gatts_create_attr_tab(battery_level_gatt_db, gatts_if, BS_IDX_NB, BATTERY_SVC_INST_ID);
            esp_ble_gatts_create_attr_tab(ess_gatt_db, gatts_if, ESS_IDX_NB, ESS_SVC_INST_ID);
        break;

        //(...)

     case ESP_GATTS_CREAT_ATTR_TAB_EVT: {
                ESP_LOGI(GATTS_TABLE_TAG, "The number handle = %x",param->add_attr_tab.num_handle);
                if (param->create.status == ESP_GATT_OK){   //ESP_GATT_OK=0x0

                        if (param->add_attr_tab.num_handle == BS_IDX_NB) {
                            memcpy(battery_service_handle_table, param->add_attr_tab.handles,
                            sizeof(battery_service_handle_table));
                            esp_ble_gatts_start_service(battery_service_handle_table[BS_IDX_SVC]);

                        } else if (param->add_attr_tab.num_handle == ESS_IDX_NB) {
                            memcpy(ess_handle_table, param->add_attr_tab.handles,
                            sizeof(ess_handle_table));
                            esp_ble_gatts_start_service(ess_handle_table[ESS_IDX_SVC]);

                    } else {
                ESP_LOGE(GATTS_TABLE_TAG, "Create attribute table abnormally, num_handle (%d) doesn't equal to BS_IDX_NB(%d) or ESS_IDX_NB(%d)",
                             param->add_attr_tab.num_handle, BS_IDX_NB, param->add_attr_tab.num_handle, ESS_IDX_NB);
                    }
                }else{
                    ESP_LOGE(GATTS_TABLE_TAG, " Create attribute table failed, error code = %x", param->create.status);
                }
    break;
  }

        default:
           break;
    }
}

do {
        int idx;
        for (idx = 0; idx < PROFILE_NUM; idx++) {
            if (gatts_if == ESP_GATT_IF_NONE || /* ESP_GATT_IF_NONE, not specify a certain gatt_if, need to call every profile cb function */
                    gatts_if == profile_tab[idx].gatts_if) {
                if (profile_tab[idx].gatts_cb) {
                    profile_tab[idx].gatts_cb(event, gatts_if, param);
                }
            }
        }
    } while (0);

void app_main()
{
    // ---

    ret = esp_ble_gatts_app_register(ESP_BATTERY_APP_ID);
    if (ret){
        ESP_LOGE(GATTS_TABLE_TAG, "gatts app register error, error code = %x", ret);
        return;
    }

    ret = esp_ble_gatts_app_register(ESP_ESS_APP_ID);
    if (ret){
        ESP_LOGE(GATTS_TABLE_TAG, "gatts app register error, error code = %x", ret);
        return;
    }
}

I added two additional screenshots, which further demonstrate the observed behavior, to the initial post.

Thank you for your efforts!

Weijian-Espressif commented 5 years ago

@secureschwob I can not visit the Gist because of China's firewall, please send .c and .h files as an attachment. or send your source code to the mail zhiweijian@espressif.com

Weijian-Espressif commented 5 years ago

@secureschwob 2b888d1a-f721-458c-ae91-1eab84204808 I have modified your test code, please replace your hws_secure_sensor_node.c file and try and restart your phone Bluetooth to clean the cache.

Weijian-Espressif commented 5 years ago

Please check your mailbox

secureschwob commented 5 years ago

You solved my problem, thank you very much!

My key error obviously was this:

static void gatts_event_handler(esp_gatts_cb_event_t event, esp_gatt_if_t gatts_if,
                                esp_ble_gatts_cb_param_t *param)
{
    //printf("%s app_id %d gatts_if %d", __func__, param->reg.app_id, gatts_if);
    /* If event is register event, store the gatts_if for each profile */
    if (event == ESP_GATTS_REG_EVT) {
        if (param->reg.status == ESP_GATT_OK) {        
            //this!
            profile_tab[param->reg.app_id].gatts_if = gatts_if; 
            // rather than this:
            // profile_tab[ESS_PROFILE_APP_IDX].gatts_if = gatts_if;
            // profile_tab[BATTERY_PROFILE_APP_IDX].gatts_if = gatts_if;

        } else {
            ESP_LOGI(GATTS_TABLE_TAG, "Reg app failed, app_id %04x, status %d\n",
                    param->reg.app_id,
                    param->reg.status);
            return;
        }
    }

together with using different gatts_profile_event_handler for each of my services.