Hi all,

Sorry for the long post, I'm starting yet another discussion on BLE throughput, but I feel this merits a deeper look.

tl;dr - I'm getting onDataWritten callbacks only once every 2 sec.

Background

I'm trying to transfer about 20 kB of data over a BLE link, from an iPhone to a Nordic mbed kit. I'm doing this by writing 16 byte chunks with 2 byte offset (total 18 bytes) to a "write without response" (write command) characteristic. I've set the connection parameters to the minimum that's supported by iOS. Theoretically I should be able to do 6 packets of 16 bytes, per conn. interval of 20 ms, giving me about 4.8 kB/sec. I know this doesn't actually happen, and my conservative calculation says I should at least be able to transfer one packet every conn.interval, and get approx 0.8 kB/sec. Even if the conn.interval is 40 ms (the max I've set), I should still get 0.4 kB/sec.

In early phase, I was doing a request-response design where the nordic chip sends a request for a particular block and iOS responds, but this was too slow for obvious reasons. Now I switched to write-without-response and no requests from chip to phone.

iOS side

On iOS, I run a loop to write n packets every x ms. I've set x to 20 ms, 50 ms etc. and tried sending between 1 and 6 packets on every timer tick. This succeeds as far as the iPhone is concerned.

BLE (nordic) side

In the firmware, I set preferred connection parameters on initialisation, and send a parameter update on connection. I should be getting an onDataWritten callback for every packet. But I noticed strange behaviour here --

- initially, I was getting a lot of missed and repeated packets. I always got the correct number of callbacks (and thus packets received). But many packets were copies of other packets. This was repeatable in almost the same order every time. For example, for a transfer of 10 packets (#0 to #9), I would something like: 2,3,3,3,5,6,7,9,9,9. 0 and 1 would always be missing, 9 was always sent thrice etc. I guessed it was because a new packet would come in and overwrite the previous while I was still processing it. However I reduced my "processing" to barely reading in the packet with BLEDevice.readCharacteristicValue() and printing out over serial port some debug info. Then I also tried turning off DEBUG logs. No difference. I also added CRITICAL_REGION_ENTER() and ..EXIT() around the onDataWritten callback and in handleValue() call inside the BLEDevice implementation in "nordic" library, which helped a little but still had issues with larger number of blocks losing sync.

• next I tried creating 6 characteristics and transferred the data one by one. So, first block to ch 0, 2nd to ch1 and so on in a round robin way. This helped, but I also had to increase time between packets to 200 ms and sending only 1 packet per tick. With this I was able to transfer 80-100 packets fine reliably. Almost always after 136 packets, the 137th would be missed and instead, two 138 would be sent and thereafter it would lose sync.

• many times, if I sent data right after connecting, small transfer (10-20 packets) would complete very fast as expected. But it would eventually slow down (see more info below).

• I tried several other things, like using BLE_GATTS_VLOC_USER for the characteristics, disabling callback for CCCD updates and other tweaks to help with performance. I disabled all other things in the firmware like Ticker and PwmOut so as to not use any extra interrupts.

Finally I tried to print the time elapsed between successive calls to nRF51GattServer::hwCallback() and this is where I realised something out of my understanding is going on.

I noticed that the callbacks were coming in approx every 2000 ms! Sometimes I would get callbacks every 80 ms right after connecting, but within a few sec it would slow down back to every 2 sec. This meant I was only getting about one 16 byte packet per 2 sec!

Below is a log of when transfer happened fast:

Initialising | Built Aug 13 2014 16:22:39
Bluetooth initialising...
Conn. params => min=16, max=40, slave=0, supervision=500
Added service
Ready. Advertising.
____[ Connected ]______________________________________
time 0 ms
time 353 ms
Notifications enabled for 2
time 105 ms
time 1999 ms
Download RESET
time 131 ms
Offered file len=156, crc=0x1234, acceptFile=1, downloadInProgress=0
time 181 ms
.time 83 ms
.time 149 ms
.time 82 ms
.time 149 ms
.time 82 ms
.time 149 ms
.time 131 ms
.time 82 ms
.time 83 ms
.File transfer took 1.1 sec

and here is another log where you can see the slow-down occurring after a while:

Initialising | Built Aug 13 2014 16:22:39
Bluetooth initialising...
Conn. params => min=16, max=40, slave=0, supervision=500
Added service
Ready. Advertising.
____[ Connected ]______________________________________
time 0 ms
time 292 ms
Notifications enabled for 2
time 165 ms
time 1689 ms
Download RESET
time 245 ms
Offered file len=1267, crc=0x1234, acceptFile=1, downloadInProgress=0
time 181 ms
.time 149 ms
.time 82 ms
.time 149 ms
.time 82 ms
.time 149 ms
.time 82 ms
.time 149 ms
.time 82 ms
.time 149 ms
.time 82 ms
.time 149 ms
.time 82 ms
.time 149 ms
.time 82 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 83 ms
.time 132 ms
.time 148 ms
.time 82 ms
.time 149 ms
.time 82 ms
.time 149 ms
time 0 ms
.time 1716 ms <-- note slow down point
.time 2044 ms
.time 1979 ms
.time 2044 ms
.time 1979 ms
.time 1979 ms
.time 1979 ms
.time 1979 ms
.time 2044 ms
.time 1979 ms
.time 2044 ms
.time 1979 ms
.time 1979 ms
.time 1979 ms
.time 1979 ms
.time 1979 ms
.time 1979 ms
.time 2044 ms
....

It seems some sort of power management is kicking in, slowing down the hardware ??

So I guess my question is: why is this happening, and how can I investigate this further? Is this on BLE_API side, or the nordic softdevice side, or in my code? I would be happy to help with any kind of debugging. Please help!

For reference, I've successfully been transferring about 128 kB of data in under 3 min, using almost exactly the same method, with the TI CC2541.

Thanks.

This looks curious. The code in nRF51822 is a fairly narrow wrapper around the soft-device when it comes to handling those callbacks (and the soft device doesn't normally exhibit this issue, the dfu firmware upgrade code operates fairly similar to your scenario). Could you produce a minimal test code that exhibits this behaviour, so that it will be easier to narrow it down? If others can't replicate your issue it could be hard to fix.

Exactly, I didn't see anything obviously cpu-hogging in the BLE wrapper over nordic SDK. Except perhaps CCCD callbacks, which I already disabled. I feel it might be an iOS issue?

I've factored out the transfer code from my project, and created a new public project here: http://mbed.org/users/pvaibhav/code/FileTransferExample/

To track the time between callbacks, you can add the following at line 245 in nRF51GattServer.cpp in the nRF51822 library code.

    static Timer t;
    t.stop();
    printf("%d ms since last nRF51GattService::hwCallback\r\n", t.read_ms());
    t.reset(); t.start();

I'm not supplying the iOS code (yet) as it's part of a commercial product and factoring out just the file transfer part will take long. But it's quite simple to re-implement in another test client. Protocol is:

1. send 32bit value of all zeros to the fileInfo characteristic, to "reset" the download machine.

2. send another two 16 bit values to fileInfo, packed as a single 32bit value. First uint16 is the length of data being transferred in bytes, next uint16 can be anything, it's ignored.

3. now start sending 18 byte packets to the 6 channels one after another round-robin starting from ch 0. First 2 bytes in the packet is a uint16 specifying block number (starting from 0 to fileLength / 16) and next 16 bytes contains the data (can be all zeros, ignored).

the TransferService.cpp file will make this very clear (the packet structs are defined on top).

Please let me know if you need any other info.

Hello Prashant,

Thanks for raising this interesting example.

There is no automatic power management kicking in from the BLE_API (or mbed). Not yet. It could be that the soft-device is running out of some buffers. I'll try to reproduce this behaviour first.

rohit.

Prashant,

I've reproduced the slowdown you report. I'll consult experts from Nordic to help explain this behaviour.

My work can be found at: http://mbed.org/teams/Bluetooth-Low-Energy/code/BLE_StreamDownloader/

rohit.

Hi Rohit,

It's worrying and relieving at the same time, to find that the issue is reproducible also on non-iOS devices. I've cross-posted this question on Nordic devzone (but no responses so far). I'll also be trying to build this with nordic SDK directly, bypassing mbed BLE, to see if it makes a difference. Will keep you posted - I'm anxiously waiting for a resolution.

Thanks.

Hi guys,

Sorry for a bit late response. I believe it's the automatic connection parameter update request from the nRF51 caused the connection interval changed.

As you can find in the projectconfig.h file we have:

#define CFG_GAP_CONNECTION_MIN_INTERVAL_MS         500                      /**< Minimum acceptable connection interval */
    #define CFG_GAP_CONNECTION_MAX_INTERVAL_MS         1000                     /**< Maximum acceptable connection interval */
    #define CFG_GAP_CONNECTION_SUPERVISION_TIMEOUT_MS  4000                     /**< Connection supervisory timeout */
    #define CFG_GAP_CONNECTION_SLAVE_LATENCY           0                        /**< Slave Latency in number of connection events. */

These macro later on will be the input variables for the preferred connection parameter in btle_gap_init() in btle_gap.cpp

So after we have connection established, the nRF51 will try to send the connection connection parameter request (after a fixed 5 second delay, check FIRST_UPDATE_DELAY). And the central device will response and update the connection parameter accordingly.

We have the maximum connection interval at 1000ms, and this explain why you have very low through put.

I did a quick test and changed the minimum connection interval to 50 and maximum to 100ms (instead of 500 and 1000ms). And here is the result:

You can find the request from the slave, then the master accepted and sent the actual update on the connection parameter (LL_CONNECTION_UPDATE_REQ). And you can find after 16 event instances, the new connection interval was applied, changed from the default 48.75ms to the new one, 97.5ms.

The trace, you see in the picture, was captured by the nRF51 sniffer, if you have a PCA10000 dongle or PCA10001 evaluation kit, you can run the sniffer on those board and capture over the air packet. It's easier to debug with that tool.

Please have a try and let me know if the issue remains.

Also, please be noted that, if you change them to too low maximum and minimum preferred connection interval, the central device will reject them. Eventhough the minimum conn interval by spec is 7.5ms, the lowest one you can get with iOS is about 20ms. Please have a look at the Bluetooth design guideline by Apple.

Hung Bui,

WOW, I can confirm this solves the issue. I'm getting even better performance than I expected. I can actually send out a full 6 packets per CI now, and can transfer the entire 20kB of data in 10 sec flat.

What I'll do now is investigate why the updateConnectionParameters() function call has no effect and the hardcoded values are being used. But it's not a big deal.

Thank you so much for looking into it! I cannot thank you enough.

Prashant,

From the comment header above sd_ble_gap_conn_param_update() in nRF51822/nordic/nrf-sdk/ble_gap.h:

Could this explain why your parameters aren't taking effect?

rohit.

Hi Rohit,

I'm setting the supervision timeout to 5000 ms (value 500 in 10ms units), max interval to 40ms (value 32) and slave latency to 0.

So the constraint holds. Actually I verified that the parameter update is having an effect, but after 5 sec, the softdevice sends another update, this time the hardcoded one, cancelling the values I set.

But now I'm having another problems - changing hardcoded conn.parameters worked, with FAST transfers through 6 parallel "channels". But when I cut back to only a single characteristic to transfer data, I'm getting a lot of missed or duplicated packets (about 75% packet loss) when sending "without response." Sending with response works fine, but then the throughput is 5-6 times slower (probably because only one packet can be sent per CI). Any ideas how to speed this up?

Currently I'm getting effective throughput of 0.2 kB/sec. I'd like to reach 1 kB/sec - that will meet our requirements.

Thanks!

I also witness packet loss when using write_without_response; although 75% packet loss seems high. Using the normal write request is reliable, but it takes around 13 seconds to transfer 1KB of data, so the throughput is similar to what you report.

Even if 6 characteristics are used in parallel, BLE link layer allows only one command/response transaction to be active between the client and the server at a time. So if having 6 channels speeds things up, perhaps there is a bottleneck above the link layer.

The soft-device specification mentions the maximum data bandwidth which can be expected over BLE; you should refer to that for comparison.

Nordic's SDK includes a over-the-air DFU bootloader which transfers new firmware as a data stream over ble. We can refer to that application to study how they achieve high data rates.

Same here, packet missing on the direction from central's client to peripheral's server.

Actually I found that when I did a write command from central to a characteristic on the mbed server, if the data packet was more than 8 bytes, I would not receive a call back in onDataWritten() in main.c. If it's less than 9 bytes, everything fine, no packet loss.

I tried to go deeper and found that we actually receive no call back for write event in btle_handler() in btle.cpp when there is more than 8 bytes in the data packet. This event handler is called directly from the S110 stack.

This is pretty strange since we haven't experienced this issue with the S110 before.

Hi all,

With the 6 channels, I was using write-without-response, so I was able to push several packets per CI. However with only 1 channel, several packets are lost. I suspect it's because of the softdevice running out of buffers, and one of the existing buffers gets overwritten before it can be processed.

I also noticed with this method, if I was sending out notifications, they would "loop back" to me — I would receive them in my app-level buffer after using `readCharacteristicValue`.

I hoped all of this could be solved if I wrapped all rx/tx buffer accesses with a mutex. But this did not help, which leads me to believe that the buffer overwriting is happening outside of my app. With 6 "channels" each incoming packet is written to the next available location in memory, reducing the chances that a buffer will get overwritten by another incoming packet before it's read/processed by the app.

What do you think?

I would like to clarify something here so that there is no misunderstanding, since this will probably uncover something amiss with the mbed handling of nRF51 events and data:

• BLE is reliable transport, meaning no packet loss ever
• Packets will be retrasmitted indefinitely until they finally arrive to the peer side
• Write Commands and Notifications use what the Nordic API calls "application" packets. Write Requests and Indications (among other) use "system" buffers, there is a big difference between those.
  • Application packets are acknowledged via BLE_EVT_TX_COMPLETE, which is translated into a onDataWritten() callback
  • System packets depend on a response from the peer

Carles

I am not sure what you call "channel", do you mean characteristic?

There are no channels in BLE, it's just a constant stream of data directed to one or more characteristics. In any case, and for the S110 7.0.0 SoftDevice, which is the one currently used in the mbed repos,

If you want high throughput your only options are to send:

• Write Commands as a client (aka Write Without Response)
• Notifications as a server

Both use application packets, of which you get *7* with the S110 7.0.0. That means you can place 6 packets per connection event into the BLE stack's buffers (there's one spare buffer for performance reasons), which gives you a throughput of:

max_throughput =   6 (packets per connection interval) 
                 * 20 (max app bytes per packet) 
                 * 8 (bits in a byte) 
                 * 1000 (ms in a second) 
                 / 7.5 (ms connection interval) 
                 = 128Kbit/s

When running internal tests at Nordic we verify that such a throughput (or something similar) is indeed possible to obtain. Some phones however limit the shortest connection interval allowed (I believe the iPhone limits it to 20ms, restricting the throughput to 48Kbit/s). If some packets are lost due to noise or other factors, they will be retransmitted until the reach their destination, potentially lowering the throughput (although in real life, and thanks to frequency hopping, this is usually not a big factor).

Since those are packets, and there are no channels, the following applies:

• You have 6 packets, each with (up to) 20 bytes of app data available for transmission every connection interval
• This applies to each direction (6 from the client to the server and 6 from the server to the client) without affecting the throughput
• Those packets can be Write Commands or Notifications, and they can target one single characteristic or multiple ones

Hope this helps,

Carles

@Carles: Sorry for causing confusion. What I meant was the missing of onDataWritten() call back, not packet missing.

The write command packet was acked on link layer (with correct SN and NESN) but there was no call back from the stack to the application if the length of the payload was >8 bytes.

Hi Carles,

thanks for the reply. By channels I mean 6 separate characteristics, I just named them channels.

I'm using the same scheme you've suggested - write without response from phone -> nrf and notifications from nrf -> phone. I've configured the CI range to be 20 ms - 40 ms (of which the iPhone seems to pick 40 ms, sadly). Each packet I send is 20 bytes (containing 16 bytes of payload and 4 bytes for identification).

With this scheme, the problem I observe is that the onDataWritten callback is only called about 25% of the time (e.g. sending 1200 packets from the phone, I receive only 350). For instance, please see below an excerpt from debug logs (I'm counting every received "data" packet. At the end of transmission of 1282 blocks, only 371 were received by the chip):

iPhone (transmitting) side:

2014-08-25 16:36:32.959 app-vocca-test[12261:60b] File Transfer Progress 99.53
2014-08-25 16:36:32.961 app-vocca-test[12261:60b] Sent block 1277
2014-08-25 16:36:32.963 app-vocca-test[12261:60b] File Transfer Progress 99.61
2014-08-25 16:36:32.964 app-vocca-test[12261:60b] Sent block 1278
2014-08-25 16:36:32.965 app-vocca-test[12261:60b] File Transfer Progress 99.69
2014-08-25 16:36:32.967 app-vocca-test[12261:60b] Sent block 1279
2014-08-25 16:36:32.969 app-vocca-test[12261:60b] File Transfer Progress 99.77
2014-08-25 16:36:32.991 app-vocca-test[12261:60b] Sent block 1280
2014-08-25 16:36:32.992 app-vocca-test[12261:60b] File Transfer Progress 99.84
2014-08-25 16:36:32.994 app-vocca-test[12261:60b] Sent block 1281
2014-08-25 16:36:32.995 app-vocca-test[12261:60b] File Transfer Progress 99.92
2014-08-25 16:36:32.996 app-vocca-test[12261:60b] Sent block 1282

Nordic side (receiver):

Expected 1, got 1209 (total 355/1282)
Expected 1, got 1216 (total 356/1282) <-- note missing packets 1210 to 1215
Expected 1, got 1217 (total 357/1282)
Expected 1, got 1229 (total 358/1282) <-- missing packets
Expected 1, got 1230 (total 359/1282)
Expected 1, got 1238 (total 360/1282) ... and so on
Expected 1, got 1239 (total 361/1282)
Expected 1, got 1245 (total 362/1282)
Expected 1, got 1246 (total 363/1282)
Expected 1, got 1255 (total 364/1282)
Expected 1, got 1256 (total 365/1282)
Expected 1, got 1268 (total 366/1282)
Expected 1, got 1269 (total 367/1282)
Expected 1, got 1272 (total 368/1282)
Expected 1, got 1273 (total 369/1282)
Expected 1, got 1280 (total 370/1282)
Expected 1, got 1281 (total 371/1282)

This behaviour is also observed with Android phones as transmitter.

This is all I'm doing in my onDataWritten() callback (read the packet and send up to the 'download handler' which prints the log messages above)

    } else if (handle == dataPoint.getHandle()) {

        uint16_t len = sizeof(DataPacket);

       DataPacket p;

        ble->readCharacteristicValue(handle, (uint8_t*) &p, &len);

        if (packetReceivedCallback)
            packetReceivedCallback(p);

        return;

    }

Definition of DataPacket:

typedef struct {
    uint8_t type;
    uint8_t len;
    uint8_t data[18];
} DataPacket;

I will try Hung Bui's suggestion and restrict packet size to 8 bytes and see if that helps.

Thanks!

UPDATE: setting packet size to 8 byte doesn't help.

UPDATE 2: I've found that if I send the next packet (from phone) only after I receive a 'send next packet' (notification) from the pcb, the transfer succeeds. If I transfer the packets at a fixed rate from the phone, there are missed packets on receiving side.

Thanks for the clarification.

I understand, is that still the case if you use a single characteristic to send all your data (i.e. send notifications and receive write commands to the same characteristic)? This looks like an issue in the mbed layer, I will spend some time this week to try and resolve this.

Carles

Yes problem persists when using a single characteristic for all data transfer. I also feel it's an mbed issue. I'm debugging it on my end as well and will post updates if I get anywhere. Thanks.

Hi,

Just a small update, regarding my issue with >8 bytes payload length, I was my mistake. I didn't check the max length of the characteristics. In BLE UART example, the max length is 8 bytes when we declare the characteristics. I changed to 20, then it fixed my issue. Thanks to Carles.

Prashant,

Carles has offered an explanation for the behaviour observed with write-without-response commands. It has to do with the fact that the value of the transferFileBlock characteristic may get updated faster than the application callback can process the changes; this may happen if the BLE stack receives several write updates in quick succession before being able to issue callbacks. In the callback, reading the value of the characteristic to determine the active blockNumber would see a rolled-forward state for the transfers.

I'll be modifying the callback mechanism so that onDataWritten() callback receives the data as well. These changes, together with several other enhancements, should be arriving soon (within a day).

thanks, Rohit.

Hi Prashanth,

Here's a diff which will address the issue. I've tested it. It will be making out into a release very shortly; but you can begin to use it right-away if you wish.

thanks for bringing this to our attention, Rohit.

Hi Rohit, thanks for the diff. Look at my result --

SUCCESS:: file downloaded in 9.65 sec (2.07 kB/s)

It works! I used the following parameters/conditions:

• connection interval: 20 ms - 40 ms
• 20 byte per 'write command' (no response) with 16 byte of payload
• total payload approx 20 kByte
• chip acknowledges every received packet with a 4 byte 'notification' including the packet #
• but phone doesn't wait for ACK, it's sending 4 packets every 20ms from the phone

With these conditions it's working very well.

When I increased to 6 packets per 20ms (effective 3ms/packet), or 4 packets per 16 ms (effective 4ms/packet), I got missed packets again. However, with 4 packets per 20ms it works perfectly fine (effective 5ms/packet). I can imagine with Android I might even get several times faster throughput due to being able to push the CI down to 7.5ms.

Thank you so much for making this improvement fast.

This "missed packets" issue sounds like a mishandling of some sort. If you could perhaps share the details and/or allow us to reproduce this we could probably fix it.

As I mentioned in another post, missing packets is simply not possible with BLE, so there has to be an issue with the code somewhere, be it on the mbed layers or your app (the SDK and SD are very thoroughly tested and I would consider it unlikely for them to be causing it).

Carles

BTW a useful pattern I noticed in Nordic's BLE firmware upgrade code is only acknowledging every N'th packet; As Carles mentioned, the lower layers are reliable so this should be sufficient and would reduce the load in the BLE stack.

I tried this, as well as removing ACK altogether. This didn't affect the so-called "missing packets." I added mutex locks around my handling code in the firmware, but it doesn't seem to make a difference either.

I agree, I think this is now a "problem" on the iPhone side, probably the phone's BLE queue is overwhelmed. Actually I wouldn't call it a problem at all, since I'm still getting 3x the throughput compared to TI, and 2x the throughput we hoped for this product.

Here's my justification: I gathered statistics of how many packets the firmware receives per second. Based on this I determined:

SUCCESS:: file downloaded in 9.32 sec (2.15 kB/s)
Disconnected after 20.0 sec
Average CI=6.67 ms (total = 8569.0 ms over 1285 samples)

Important to note is that it takes on average 6.67 ms per packet. If my theory that the iPhone picks 40ms CI is correct, and 6 packets are delivered in that CI, that gives 6.67 ms per packet. This matches exactly what I measured.

Our Android developer is currently away, as soon as he's back I'm gonna test it on Android and report the results.

I've been trying to follow this thread as I'm facing with a similar problem (transferring large amounts of data from the mbed device to the phone, and from the phone to the device). At first, I thought about using the naive solution of writing data to one characteristic and waiting for ack notification on another, then send the next packet. But after reading this thread, it seems like this might be too slow. What is the best practice to achieve reliable high throughput? Is there an updated example somewhere (ideally, with iOS/Android source code as well)? Should I use multiple characteristics like Prashant? What is the method that has been adopted to do DFU?