Why don't I get a BLE_GATTS_EVT_SYS_ATTR_MISSING event?

[brianreinhold]

This discussion got mixed up with a discussion about what Nordic means by a 'system attribute' (which is still not clear). In any case, in that discussion I was trying to save pairing/bonding information so I could restore it on a reconnect. The pairing keys worked. I grabbed the keys on the pairing complete event, saved them to a file, read them from that file, and gave them to the peer when asked on a reconnect in the BLE_GAP_EVT_SEC_INFO_REQUEST event.

But the CCCD information doesn't work that way. I can't restore the CCCD state using the same approach, because I cannot initialize the CCCD myself from the application (even prior to a connection). Instead I was told I need to get the 'system attributes' by calling this method sd_ble_gatts_sys_attr_get(), save them to a file, and restore them by calling this method sd_ble_gatts_sys_attr_set() when I get a BLE_GATTS_EVT_SYS_ATTR_MISSING event.

Fantastic! Sounds easy enough. However, I never get a BLE_GATTS_EVT_SYS_ATTR_MISSING event. I get this event BLE_GAP_EVT_SEC_INFO_REQUEST to restore the keys, so that works. What is missing?

[tesc]

Hi,

You will get the BLE_GATTS_EVT_SYS_ATTR_MISSING event if the peer requests a read on any of the system attributes.

In the case where you send indications or notifications before the peer requests such a read, for instance you want to perform a sd_ble_gatts_service_changed(), you need to do the sd_ble_gatts_sys_attr_set() first.

In our SDK, this is done for instance inside service_changed_send_in_evt() in gatt_cache_manager.c (part of Peer Manager), where the function local_db_apply_in_evt() calls gscm_local_db_cache_apply() in gatts_cache_manager.c, which eventually calls sd_ble_gatts_sys_attr_set().

Regards,
Terje

[brianreinhold]

There are two independent issues happening here. First, I am using the pc-ble-driver. I make direct sd_* calls. I acutally find that easier in most cases than trying to figure out what the SDK is doing and porting it to the pc-ble-driver.

In any case

• issue #1 has to do with restoring the state of the CCCDs that were set by the collector in a previous connection. I was told to use the sd_ble_gatts_sys_attr_set() function in the BLE_GATTS_EVT_SYS_ATTR_MISSING. I saved the state from a sd_ble_gatts_sys_attr_get() function in the previous connection, and then on a reconnection waited for the BLE_GATTS_EVT_SYS_ATTR_MISSING event to restore it. It never happened. So what I have done instead is to ignore those instructions and just restore it in the connection event.

• issue #2 is trying to do a service changed indication on a reconnect. No matter what I do for prep, the sd_ble_gatts_service_changed() fails, and it always fails in the same way. From start handles 0-13 I get invalid handle, and for every handle value above that I get a BLE_ERROR_SYS_ATTRS_MISSING error. This happens regardless of the number of get and set calls I do prior to making the service changed attempt. I see from the table returned from the 'get' call that there is only one entry and that handle is 13.

[tesc]

Hi,

I registered a ticket for this in our internal systems. Clearly a bug. If you observe other misbehavior from the system then please let me know and I will register that as well. Your feedback is highly appreciated.

Regards,
Terje

[brianreinhold]

You are correct about my stupid if statement. I am reporting the wrong error. When I correct that I get (instead) NRF_ERROR_INVALID_STATE; operation not permitted in this state. That is also a problem because I want to invoke the service changed operation as soon as possible to be sure that the bonded client does not try and perform an operation that makes no sense. Anything the client tries to do (read, write, etc) except for service discovery will be done with (potentially) incorrect handle values.

I will add that the client IS writing the CCCD of the service changed characteristic. I report it in the log here:

Client Enabling CCCD of characteristic handle 13 with value 2 at time 2016

Since I have no guaranteed way to get the handle value of the service changed characteristic I cannot print out a good log statement. But looking at the saved table values I see that 13 is the service changed handle.

[tesc]

Hi,

For locating the CCCD of the Service Changed Characteristic, you can do as is done in the function service_changed_cccd() in gatt_cache_manager.c of SDK 16:

/**@brief Function for getting the value of the CCCD for the service changed characteristic.
 *
 * @details This function will search all system handles consecutively.
 *
 * @param[in]  conn_handle  The connection to check.
 * @param[out] p_cccd       The CCCD value of the service changed characteristic for this link.
 *
 * @return Any error from @ref sd_ble_gatts_value_get or @ref sd_ble_gatts_attr_get.
 */
static ret_code_t service_changed_cccd(uint16_t conn_handle, uint16_t * p_cccd)
{
    bool       sc_found = false;
    uint16_t   end_handle;

    ret_code_t err_code = sd_ble_gatts_initial_user_handle_get(&end_handle);
    ASSERT(err_code == NRF_SUCCESS);

    for (uint16_t handle = 1; handle < end_handle; handle++)
    {
        ble_uuid_t uuid;
        ble_gatts_value_t value = {.p_value = (uint8_t *)&uuid.uuid, .len = 2, .offset = 0};

        err_code = sd_ble_gatts_attr_get(handle, &uuid, NULL);
        if (err_code != NRF_SUCCESS)
        {
            return err_code;
        }
        else if (!sc_found && (uuid.uuid == BLE_UUID_GATT_CHARACTERISTIC_SERVICE_CHANGED))
        {
            sc_found = true;
        }
        else if (sc_found && (uuid.uuid == BLE_UUID_DESCRIPTOR_CLIENT_CHAR_CONFIG))
        {
            value.p_value = (uint8_t *)p_cccd;
            return sd_ble_gatts_value_get(conn_handle, handle, &value);
        }
    }
    return NRF_ERROR_NOT_FOUND;
}

When you get NRF_ERROR_INVALID_STATE, it may be because of a concurrent ATT_MTU exchange, or because the CCCD is not enabled.

Regards,
Terje

[brianreinhold]

Any news on the ble_gatts_evt_sys_attr_missing event?

[tesc]

Hi,

In the post you referred to I was referring to misbehavior from DevZone, and not to anything related to ble_gatts_evt_sys_attr_missing.

What are the remaining issues that you see with ble_gatts_evt_sys_attr_missing?

Regards,
Terje

[brianreinhold]

It still does not work. I cannot invoke a service changed and I cannot indicate/notify a peer on a reconnect UNLESS the peer rewrites the CCCDs.

[tesc]

Hi,

In order to figure out what is actually going on here, we would need a sniffer trace. For instance you can use the nRF Sniffer, which uses an nRF Dongle or DK.

Regards,
Terje

[brianreinhold]

Fullscreen 2055.Output.txt Download

Microsoft Windows [Version 10.0.17763.973]
(c) 2018 Microsoft Corporation. All rights reserved.

E:\projects\BleTester\BtleTester\exe>BtleTester.exe
Serial port used: COM9
Baud rate used: 1000000
Waiting on MQTT
Message with token value 61 delivery confirmed
Message arrived
   topic: pcha/message/WAN/Gyannea/CODE
   message: Payload: {"id":2,"Command":"config","common":{"deviceName":"BloodPressureOne","btaddress":"C00000001001","dis":{"trapRead":false,"useDefaultRegCert":true,"systemId":"FEEDABEEDEAD1001",
"manufacturer":"LNI, Inc.","model":"BP_0001","serial":"snBp0001","firmware":"fw0.2.1"},"cts":{"currentTimeChar":{"trapRead":true,"allowWrite":true,"adjustReason":"None"}},"invokeServiceChanged":fa
lse},"bp":{"trapMsmtCharRead":false,"bpFeatureChar":{"trapRead":false,"bodyMovement":true,"cuffFit":true,"irregularPulse":true,"pulseRange":true,"msmtPosition":true},"msmts":[{"hasTimeStamp":true,
"units":"mmHg","hasUserId":false,"systolic":"110","diastolic":"62","mean":"80","pulseRate":"49","delay":1000},{"hasTimeStamp":true,"units":"kPa","hasUserId":false,"systolic":"14.66","diastolic":"8
.25","mean":"10.64","pulseRate":"52","delay":1000},{"hasTimeStamp":true,"units":"mmHg","hasUserId":false,"systolic":"112.5","diastolic":"63.8","mean":"79.5","pulseRate":"44","delay":1000},{"hasTim
eStamp":true,"units":"kPa","hasUserId":false,"systolic":"15.00","diastolic":"8.50","mean":"10.60","pulseRate":"67","delay":1000}]}}
MQTT Signaled
Mqtt queue entry signaled
jsonString read from MQTT queue
0x01 10 ad de ee ab ed fe
0x01 10 00 00 00 c0

Sending payload {"rspId":2,"success":true,"body":"Config command received for specialization Blood Pressure Monitor"}
Waiting on MQTT
Message with token value 62 delivery confirmed
Message arrived
   topic: pcha/message/WAN/Gyannea/CODE
   message: Payload: {"id":3,"Command": "startAdvertising"}
MQTT Signaled
Mqtt queue entry signaled
jsonString read from MQTT queue
Waiting on MQTT
Run signaled
//================================================= Here the Nordic BP specialization is started.
Creating or opening file BloodPressureOne for reading.
File not found. It will be created when the specialization exits
Serial port used: COM9
Baud rate used: 1000000
Info: Successfully opened COM9. Baud rate: 1000000. Flow control: none. Parity: none.
Status: 6, message: Target Reset performed
Status: 7, message: Connection active
Service initiated
Characteristic 0x2A23 initiated
Characteristic 0x2A29 initiated
Characteristic 0x2A24 initiated
Characteristic 0x2A25 initiated
Characteristic 0x2A26 initiated
Characteristic 0x2A2A initiated
Service initiated
Characteristic 0x2A2B initiated
Advertising data set
Service initiated
Characteristic 0x2A35 initiated
Characteristic 0x2A49 initiated
//========================================== Advertising started
Started advertising at time 0

Sending payload {"rspId":3,"success":true,"body":"Advertisement has started"}
Message with token value 63 delivery confirmed
//========================================== Connected to Android Client (the time is elapsed milliseconds from BP peripheral start)
Connected at time 3281, connection handle 0x0001
Connection parameters update at time 4110: min: 6 max: 6 supervision timeout: 2000 slave latency: 0
//========================================== Android enabling service changed characteristic
Client Enabling CCCD of characteristic handle 13 with value 2 at time 4297
Connection parameters update at time 4719: min: 39 max: 39 supervision timeout: 2000 slave latency: 0
//========================================== Android reading current time
Characteristic 2A2B read at time 5078
Read update reply response 0
//========================================== Android requesting pairing because it tried to enable the BP Meausurement Characterisitic - secured
//                                           so it Got 'insufficient authentication' error
Peer requesting pairing at time 5469; Peer parameters:
    bonding: 1
    io_caps: 4
    max key size: 16
    min key size: 0
    MITM supported: 1
    Out of band supported: 0
    secure connections (LESC) supported: 1
    enable generation of keypress supported: 0
    peer keys distributed: LTK 1  IRK 1  LNK from LTK 1  SIGN 1
    own keys requested: LTK 1  IRK 1  LNK from LTK 1  SIGN 1
Responding with own parameters at time 5469; Own parameters:
    bonding: 1
    io_caps: 3
    max key size: 16
    min key size: 8
    MITM supported: 0
    Out of band supported: 0
    secure connections (LESC) supported: 0
    enable generation of keypress supported: 0
    peer keys requested: LTK 1  IRK 1  LNK from LTK 0  SIGN 0
    own keys distributed: LTK 1  IRK 1  LNK from LTK 0  SIGN 0
Result of sending security params 0
Connection parameters update at time 5813: min: 6 max: 6 supervision timeout: 2000 slave latency: 0
Security settings reported at time 5906:
    security level: 2
    security mode: 1
    key length: 16
Result of pairing 0 at time 5953:
    bonded: 1
    peer keys: LTK 1  IRK 1  LNK from LTK 0  SIGN 0
    own keys: LTK 1  IRK 1  LNK from LTK 0  SIGN 0
Keys:
    peer LTK 66, 54, 4A, DC, 5E, FC, 20, 41, AB, 15, 21, 6B, FF, FE, 0E, 28
    peer IRK 91, AC, 7A, 40, 9C, 78, 73, 42, 67, 51, 78, 3E, F3, A8, BB, 77
    peer Addrress D0, F0, C4, A6, B4, 88
    own LTK  E7, 5D, 8C, D7, B7, BE, 00, B0, 53, 28, 86, 7B, 90, 7B, 46, 7A
    own IRK D6, 31, FE, 19, F1, AE, 18, E8, E2, 76, 97, F7, F0, E9, 55, E6
//========================================== Android Re-enabling BP measurement characteristic after pairing
Enabling CCCD with 2 at time 6453
//========================================== Nordic BP device sends measurements
Send systolic 110 diastolic 62 mean 80
Confirmation of indication on handle 33 received at time 6485
Connection parameters update at time 6938: min: 39 max: 39 supervision timeout: 2000 slave latency: 0
Send systolic 14.66 diastolic 8.25 mean 10.64
Confirmation of indication on handle 33 received at time 7516
Send systolic 112.5 diastolic 63.8 mean 79.5
Confirmation of indication on handle 33 received at time 8594
Send systolic 15.00 diastolic 8.50 mean 10.60
Confirmation of indication on handle 33 received at time 9563
End of primary pre-configured send

Sending payload {"evtId":1,"event":"Pre-configured measurements sent."}
//========================================== Now the controller will send a command to the BP device to disconnect
Waiting on Run
Message with token value 64 delivery confirmed
Message arrived
   topic: pcha/message/WAN/Gyannea/CODE
   message: Payload: {"id":4,"Command": "stop"}
MQTT Signaled
Mqtt queue entry signaled
jsonString read from MQTT queue
//========================================== Disconnected - save pairing keys and CCCDs
Disconnected at time 10781
Disconnect completed
Saving data to file at time 10797
Saving file BloodPressureOne.
saveDataLength: 20 saveDataBuffer 0D 00 02 00 02 00 1E 00 02 00 00 00 22 00 02 00 02 00 F7 CE
Info: serial port COM9 closed.
Closed at time 10797

Cleaned up shut down specialization

Sending payload {"evtId":2,"event":"Specialization Disconnected."}
Message with token value 65 delivery confirmed

Sending payload {"rspId":4,"success":true,"body":"Specialization stopped"}
Waiting on MQTT
Message with token value 66 delivery confirmed
Message arrived
   topic: pcha/message/WAN/Gyannea/CODE
   message: Payload: {"id":6,"Command":"config","common":{"deviceName":"BloodPressureOne","btaddress":"C00000001001","dis":{"trapRead":false,"useDefaultRegCert":true,"systemId":"FEEDABEEDEAD1001",
"manufacturer":"LNI, Inc.","model":"BP_0001","serial":"snBp0001","firmware":"fw0.2.1"},"cts":{"currentTimeChar":{"trapRead":true,"allowWrite":true,"adjustReason":"None"}},"invokeServiceChanged":fa
lse},"bp":{"trapMsmtCharRead":false,"bpFeatureChar":{"trapRead":false,"bodyMovement":true,"cuffFit":true,"irregularPulse":true,"pulseRange":true,"msmtPosition":true},"msmts":[{"hasTimeStamp":true,
"units":"mmHg","hasUserId":false,"systolic":"110","diastolic":"62","mean":"80","pulseRate":"49","delay":1000},{"hasTimeStamp":true,"units":"kPa","hasUserId":false,"systolic":"14.66","diastolic":"8
.25","mean":"10.64","delay":1000},{"hasTimeStamp":true,"units":"mmHg","hasUserId":false,"systolic":"112.5","diastolic":"63.8","mean":"79.5","pulseRate":"44","delay":1000},{"hasTimeStamp":true,"uni
ts":"kPa","hasUserId":false,"systolic":"15.00","diastolic":"8.50","mean":"10.60","delay":1000}]}}
MQTT Signaled
Mqtt queue entry signaled
jsonString read from MQTT queue
0x01 10 ad de ee ab ed fe
0x01 10 00 00 00 c0

Sending payload {"rspId":6,"success":true,"body":"Config command received for specialization Blood Pressure Monitor"}
Waiting on MQTT
Message with token value 67 delivery confirmed
//========================================== Restart Nordic BP peripheral
Message arrived
   topic: pcha/message/WAN/Gyannea/CODE
   message: Payload: {"id":7,"Command": "startAdvertising"}
MQTT Signaled
Mqtt queue entry signaled
jsonString read from MQTT queue
Waiting on MQTT
Run signaled
Creating or opening file BloodPressureOne for reading.
saveDataLength: 20
saveDataLength: 20 saveDataBuffer 0D 00 02 00 02 00 1E 00 02 00 00 00 22 00 02 00 02 00 F7 CE
Serial port used: COM9
Baud rate used: 1000000
Info: Successfully opened COM9. Baud rate: 1000000. Flow control: none. Parity: none.
Status: 6, message: Target Reset performed
Status: 7, message: Connection active
Service initiated
Characteristic 0x2A23 initiated
Characteristic 0x2A29 initiated
Characteristic 0x2A24 initiated
Characteristic 0x2A25 initiated
Characteristic 0x2A26 initiated
Characteristic 0x2A2A initiated
Service initiated
Characteristic 0x2A2B initiated
Advertising data set
Service initiated
Characteristic 0x2A35 initiated
Characteristic 0x2A49 initiated
Started advertising at time 0
//========================================== Advertising started
Sending payload {"rspId":7,"success":true,"body":"Advertisement has started"}
Message with token value 68 delivery confirmed
//========================================== Connected to Android
Connected at time 500, connection handle 0x0001
Calling sd_ble_gatts_sys_attr_set with CCCD info
Result of sending encryption params 0
Security settings reported at time 1031:
    security level: 2
    security mode: 1
    key length: 16
Client Enabling CCCD of characteristic handle 13 with value 2 at time 2390
Characteristic 2A2B read at time 2484
Read update reply response 0
Message arrived
   topic: pcha/message/WAN/Gyannea/CODE
   message: Payload: {"id":8,"Command": "stop"}CODE
MQTT Signaled
Mqtt queue entry signaled
jsonString read from MQTT queue
Disconnected at time 60359
Disconnect completed
Saving data to file at time 60359
Saving file BloodPressureOne.
End of primary pre-configured send

Sending payload {"evtId":1,"event":"Specialization disconnected unexpectedly."}
saveDataLength: 20 saveDataBuffer 0D 00 02 00 02 00 1E 00 02 00 00 00 22 00 02 00 02 00 F7 CE
Waiting on Run
Message with token value 69 delivery confirmed
Info: serial port COM9 closed.
Closed at time 60375

Cleaned up shut down specialization

Sending payload {"evtId":2,"event":"Specialization Disconnected."}

Sending payload {"rspId":8,"success":true,"body":"Specialization stopped"}
Waiting on MQTT
Message with token value 70 delivery confirmed
Message with token value 71 delivery confirmed

BPNordicNoCCCD.cfaBPNordicNoCCCD.fscBPNordicNoCCCD.frmI have the Frontline BPA 600. Right now I am trying to stop the client from re-enabling when paired.

Uploaded Frontline sniffs and a text file showing the output

As far as I can tell the buffer with the CCCD info is correct

0D 00 02 00 02 00 1E 00 02 00 00 00 22 00 02 00 02 00 F7 CE

I see the service changed set, the current time not set, and the BP measurement set.

Still does not work. The client does not re-enable the measurement IF it has already done it and is paired.

[brianreinhold]

Well, I have a sniff using the Frontline sniffer and it reveals nothing. I have a client that does not re-write the CCCDs after bonding and I get no data transfer. The first time when it DOES write the CCCD, the data is transferred. The next connection, no data is transferred because the CCCD is not re-written. I knew this would not reveal anything, but the sniff is attached. This has become critical now because I have a production client that cannot work with this dongle because the CCCDs cannot be reset on a reconnect. Its a pretty important part of the BTLE standard.

The data from the get and set calls 0D 00 02 00 02 00 1E 00 02 00 02 00 F1 D1 looks correct so I have no idea what is going on. CCCDsDontWork.frmCCCDsDontWork.cfaCCCDsDontWork.fsc

[brianreinhold]

I am getting desperate to fix this issue as I cannot work with some production health device clients. If the support staff could give me a Visual Studio 2019 project that builds the ble-pc-driver then I could debug this problem myself ... or at least get a lot further. I spent two weeks some months ago trying to create the VS project for the driver but failed. I didn't want to spend any more time on it after that.

With the project I could make it a part of my solution instead of using the pre-built library. That would also allow me to test any fixes.

Would be greatly appreciated.