gattlib_connect does not succeed all the time when it should

[cryptax]

I wrote a program using gattlib that connects to a BLE device. Unfortunately, although the device is in a correct state, the connection fails many times before it eventually works. I consequently have to perform several connection attemps before I actually manage to connect.

This issue does not occur when I use gatttool: I always connect (perhaps sometimes a bit longer) provided my device/host/dongle is in a normal state of course.

That's the piece of code I use for connection:

gatt_connection = gattlib_connect(NULL, addr, BDADDR_LE_RANDOM, BT_IO_SEC_LOW, 0, 0);
if(gatt_connection == NULL){
  printf("[-] Connection failed\n");

Sample output of my program:

[>>>] Connecting to xx:xx:xx:xx:xx:xx... (attempt no=1)
[-] Connection failed
[>>>] Trying again...
[>>>] Connecting to xx:xx:xx:xx:xx:xx... (attempt no=2)
[+] Connected to xx:xx:xx:xx:xx:xx

Why is that? Is there a way I can change some settings etc so that the connection always succeeds (provided the device is there ;)?

For example, with gatttool:

$ gatttool -I -b xx:xx:xx:xx:xx:xx -t random
[xx:xx:xx:xx:xx:xx][LE]> connect
Attempting to connect to xx:xx:xx:xx:xx:xx
Connection successful
[xx:xx:xx:xx:xx:xx][LE]>

I have bluez 5.37 and the latest checkout of gattlib.

[oliviermartin]

@cryptax I have just added proper Bluez5 support (based on Bluez 5.43). I would be curious to know whether you still have the issue.
gattlib_connect() has a 6 seconds timeout. How long gatttool takes to connect to your device?

[stepen]

I experience something similar. Often the connects fails, but when it succeeds a GLib_Warning is also printed (gattlib-master as of 2017-02-11, on RaspberryPi3, BlueZ 5.43).

E.g.

./read_write 20:CD:39:B1:8E:E3 read "00002a19-0000-1000-8000-00805f9b34fb"
Read UUID completed: 57

(process:3406): GLib-WARNING **: Invalid file descriptor.

./read_write 20:CD:39:B1:8E:E3 read "00002a19-0000-1000-8000-00805f9b34fb"
Fail to connect to the bluetooth device.

(Sometimes the read just 'hangs' foever after having printed the read value...)

[oliviermartin]

I know about the warning. It should be harmless even if I am planning to fix it at some point.

Does gatttool provided by your RaspberryPi is also slow? I am wondering if the slowness issue really comes from gattlib or just the BLE device itself.
There is a possibility to increase the timeout by changing CONNECTION_TIMEOUT in https://github.com/labapart/gattlib/blob/master/src/gattlib_connect.c#L39
The timeout is actually a 2 seconds.

[stepen]

I'll try to experiment with the 2s timeout. Here's some additional data.

//Using (built-in) gattool (huge variation in response times, but always reports back - large response times could easily be a problem with the device/Adapter)
$ sudo hciconfig hci0 down; sudo hciconfig hci0 up
$ time gatttool -b 20:CD:39:B1:8E:E3 --char-read -a 0x0040
Characteristic value/descriptor: 4f

real 0m0.409s
user 0m0.000s
sys 0m0.000s

... 7 subsequent calls:
real 0m4.247s
real 0m2.099s
real 0m3.855s
real 0m1.689s
real 0m5.221s
real 0m1.978s
real 0m5.227s

---

// Using gatlib (Many fails, could very well be related to the 2s timeout)
$ sudo hciconfig hci0 down; sudo hciconfig hci0 up
$ time ./read_write 20:CD:39:B1:8E:E3 read "00002a19-0000-1000-8000-00805f9b34fb"
Read UUID completed: 4f

(process:30282): GLib-WARNING **: Invalid file descriptor.

real 0m1.715s
user 0m1.710s
sys 0m0.000s

... 5 subsequent calls:
real 0m6.763s // Fail to connect to the bluetooth device.
real 0m6.155s // Fail to connect to the bluetooth device.
real 0m1.886s // Read UUID completed: 4f
real 0m6.307s // Fail to connect to the bluetooth device
real 0m0.007s // connect: Device or resource busy (16), Error: gattlib_connect - initialization, Fail to connect to the bluetooth device. [Never recovers from this until 'hciconfig down/up' is executed]

[stepen]

Tried to change the CONNECTION_TIMEOUT to 6 (and rebuild), provided the same 'picture' as before.. with many connection-fails, just with a longer timeout period (~CONN_TIMEOUT+4)

$ sudo hciconfig hci0 down; sudo hciconfig hci0 up
$ time ./read_write 20:CD:39:B1:8E:E3 read "00002a19-0000-1000-8000-00805f9b34fb"
Read UUID completed: 4d

(process:30476): GLib-WARNING **: Invalid file descriptor.

real 0m0.429s
user 0m0.410s
sys 0m0.010s

Subsequent calls:
real 0m2.115s //Read UUID completed: 4d
real 0m10.493s //Fail to connect to the bluetooth device.
real 0m10.620s //Fail to connect to the bluetooth device.
real 0m1.719s //Read UUID completed: 4d
real 0m10.109s //Fail to connect to the bluetooth device.
real 0m10.574s //Fail to connect to the bluetooth device.
real 0m10.758s //Fail to connect to the bluetooth device.
real 0m10.126s //Fail to connect to the bluetooth device.
real 0m10.262s //Fail to connect to the bluetooth device.
real 0m10.431s //Fail to connect to the bluetooth device.

(I also did 10 calls with gatttool, and none failed. Timing was avg. < 1.1s)

Finally changing the CONNECTION_TIMEOUT to 12 just resulted in failed connects after ~16s (Pattern was again the same. First connect is often OK, subsequent calls fail except a few)

[oliviermartin]

As I told stepen in another issue I have just fixed GLib_Warning in ed3ff06.

[oliviermartin]

@stepen , do you mind doing the same test with the ported gatttool. The gatttool example in the project gattlib (https://github.com/labapart/gattlib/tree/master/examples/gatttool) is the same version of the builtin gatttool but with gattlib calls.

time ./gatttool -b 20:CD:39:B1:8E:E3 --char-read -a 0x0040

[oliviermartin]

With this following source file I have almost 100% success (I have not tried write). I replaced gattlib_connect by gattlib_connect_async. I guess the issue is in gattlib_connect.

/*
 *
 *  GattLib - GATT Library
 *
 *  Copyright (C) 2016-2017  Olivier Martin <olivier@labapart.org>
 *
 *
 *  This program is free software; you can redistribute it and/or modify
 *  it under the terms of the GNU General Public License as published by
 *  the Free Software Foundation; either version 2 of the License, or
 *  (at your option) any later version.
 *
 *  This program is distributed in the hope that it will be useful,
 *  but WITHOUT ANY WARRANTY; without even the implied warranty of
 *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 *  GNU General Public License for more details.
 *
 *  You should have received a copy of the GNU General Public License
 *  along with this program; if not, write to the Free Software
 *  Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
 *
 */

#include <assert.h>
#include <stdbool.h>
#include <stdio.h>
#include <stdlib.h>

#include "gattlib.h"

typedef enum { READ, WRITE} operation_t;
operation_t g_operation;

static uuid_t g_uuid;
long int value_data;

static void usage(char *argv[]) {
	printf("%s <device_address> <read|write> <uuid> [<hex-value-to-write>]\n", argv[0]);
}

volatile bool g_operation_completed;
static void connect_cb(gatt_connection_t* connection) {
	if (connection != NULL) {
		uint8_t buffer[100];
		int len, i, ret;

		if (g_operation == READ) {
			len = gattlib_read_char_by_uuid(connection, &g_uuid, buffer, sizeof(buffer));

			printf("Read UUID completed: ");
			for (i = 0; i < len; i++)
				printf("%02x ", buffer[i]);
			printf("\n");
		} else {
			uint16_t handle = 0; //TODO: FIXME
			ret = gattlib_write_char_by_handle(connection, handle, buffer, sizeof(buffer));
			assert(ret == 0);
		}
	}
	g_operation_completed = true;
}

int main(int argc, char *argv[]) {
	gatt_connection_t* connection;

	if ((argc != 4) && (argc != 5)) {
		usage(argv);
		return 1;
	}

	if (strcmp(argv[2], "read") == 0) {
		g_operation = READ;
	} else if ((strcmp(argv[2], "write") == 0) && (argc == 5)) {
		g_operation = WRITE;

		if ((strlen(argv[4]) >= 2) && (argv[4][0] == '0') && (argv[4][0] == 'x')) {
			value_data = strtol(argv[4], NULL, 0);
		} else {
			value_data = strtol(argv[4], NULL, 16);
		}
		printf("Value to write: 0x%lx\n", value_data);
	} else {
		usage(argv);
		return 1;
	}

	if (gattlib_string_to_uuid(argv[3], strlen(argv[3]) + 1, &g_uuid) < 0) {
		usage(argv);
		return 1;
	}

	int n;
	for (n=0; n<1000; n++) {
		printf("* Connection %d\n", n);
		g_operation_completed = false;
		connection = gattlib_connect_async(NULL, argv[1], BDADDR_LE_RANDOM, BT_SEC_LOW, 0, 0, connect_cb);
		if (connection == NULL) {
			fprintf(stderr, "Fail to connect to the bluetooth device.\n");
			return 1;
		} else {
			while (!g_operation_completed);
			gattlib_disconnect(connection);
		}
	}
	return 0;
}

[stepen]

Here is some additional data.

Run #1: NEW gattlib-gatttool, Device=20:CD:39:B1:8E:E3: 59 calls, 9 fail-to-read, 3 resource busy.
Run #2: NEW gattlib-gatttool, Device=20:CD:39:B1:8E:E3: (with CONNECTION_TIMEOUT=4s): 10 calls, 1 fail-to-read, 4 resource busy.
Run #3: ORIGINAL gatttool, Device=20:CD:39:B1:8E:E3 (BlueZ, 5.23): 69 calls: 0 failed-to-read, 0 resource busy
Run #4: NEW gattlib-gatttool: Different Device (a kitchen termometer): 52 calls, 0 failed-to-read, 0 resource busy.

I've only included data for run #1 and run#2. And as I said earliere, it MIGHT well be a problem with the actual device (20:CD:39:B1:8E:E3=prototype), which the results partly hints at.

RUN #1

$ time ./gatttool -b 20:CD:39:B1:8E:E3 --char-read -a 0x0040
Characteristic value/descriptor: 5a

real    0m1.660s  // OK
user    0m0.000s
sys     0m0.010s

Subsequent:

real    0m0.147s  // OK
real    0m0.113s  // OK
real    0m0.131s  // OK
real    0m0.130s  // OK
real    0m0.095s  // OK
real    0m0.110s  // OK
real    0m0.143s  // OK
real    0m0.105s  // OK
real    0m0.106s  // OK
real    0m0.114s  // OK
real    0m0.093s  // OK
real    0m0.111s  // OK
real    0m0.129s  // OK
real    0m0.130s  // OK
real    0m0.148s  // OK
real    0m0.152s  // OK
real    0m0.119s  // OK
real    0m0.113s  // FAILED - nothing is read
real    0m2.012s  // FAILED - nothing is read
real    0m2.012s  // FAILED - nothing is read
real    0m2.006s  // FAILED - nothing is read
real    0m2.012s  // FAILED - nothing is read
real    0m2.014s  // OK
real    0m0.115s  // OK
real    0m0.130s  // OK
real    0m0.128s  // OK
real    0m0.130s  // OK
real    0m0.157s  // OK
real    0m0.096s  // OK
real    0m0.098s  // OK
real    0m0.223s  // OK
real    0m0.136s  // OK
real    0m0.099s  // OK
real    0m0.138s  // OK
real    0m0.120s  // OK
real    0m0.091s  // OK
real    0m0.149s  // OK
real    0m2.011s  // FAILED - nothing is read
real    0m2.011s  // FAILED - nothing is read
real    0m1.872s  // OK
real    0m0.108s  // OK
real    0m0.113s  // OK
real    0m0.135s  // OK
real    0m0.106s  // OK
real    0m0.153s  // OK
real    0m0.096s  // OK
real    0m0.108s  // OK
real    0m0.130s  // OK
real    0m0.148s  // OK
real    0m0.113s  // OK
real    0m0.139s  // OK
real    0m0.129s  // OK
real    0m0.139s  // OK
real    0m2.009s  // FAILED - nothing is read
real    0m2.011s  // FAILED - nothing is read
real    0m0.014s  // FAILED - connect: Device or resource busy (16)
real    0m0.014s  // FAILED - connect: Device or resource busy (16)
real    0m0.013s  // FAILED - connect: Device or resource busy (16)

Never recovers from this. 'bluetoothctl' (info 20:CD:39:B1:8E:E3) reports device as 'connected = yes'. Which explains the error, but not why it occured in the first place.
I waited 20 min to see if it would time out or something, but it did not. 'Resource busy' persisted. Only resolution is to either turn the device off and restart or disconnect via 'bluetoothctr'.

RUN #2

$ time ./gatttool -b 20:CD:39:B1:8E:E3 --char-read -a 0x0040
Characteristic value/descriptor: 57

real    0m1.645s
user    0m0.000s
sys     0m0.010s

Subsequent

real    0m3.691s  // OK
real    0m0.099s  // OK
real    0m0.140s  // OK
real    0m0.102s  // OK
real    0m4.049s  // OK - Failed to read
real    0m0.013s  // FAILED - connect: Device or resource busy (16)
real    0m0.013s  // FAILED - connect: Device or resource busy (16)
real    0m0.014s  // FAILED - connect: Device or resource busy (16)
real    0m0.013s  // FAILED - connect: Device or resource busy (16)

[oliviermartin]

Sorry, I cannot reproduce this issue with the only BLE device I have here. :-(

[ghost]

The time it takes to connect does seem to be unbearably slow, compared to the regular gatttool

[oliviermartin]

I cannot duplicate the issue with my Nordic nRF52 board.

default gatttool

$ time gatttool -t random -b DA:94:40:95:E0:87 --char-read -a 0x000e
Characteristic value/descriptor: 03 

real	0m1.170s
user	0m0.000s
sys	0m0.000s
$ time gatttool -t random -b DA:94:40:95:E0:87 --char-read -a 0x000e
Characteristic value/descriptor: 03 

real	0m0.095s
user	0m0.004s
sys	0m0.000s
$ time gatttool -t random -b DA:94:40:95:E0:87 --char-read -a 0x000e
Characteristic value/descriptor: 03 

real	0m0.111s
user	0m0.000s
sys	0m0.000s
$ time gatttool -t random -b DA:94:40:95:E0:87 --char-read -a 0x000e
Characteristic value/descriptor: 03 

Gattlib gatttool

real	0m0.109s
user	0m0.004s
sys	0m0.000s
$ time ./examples/gatttool/gatttool -t random -b DA:94:40:95:E0:87 --char-read -a 0x000e
Characteristic value/descriptor: 03 

real	0m0.530s
user	0m0.004s
sys	0m0.000s
$ time ./examples/gatttool/gatttool -t random -b DA:94:40:95:E0:87 --char-read -a 0x000e
Characteristic value/descriptor: 03 

real	0m0.138s
user	0m0.004s
sys	0m0.000s
$ time ./examples/gatttool/gatttool -t random -b DA:94:40:95:E0:87 --char-read -a 0x000e
Characteristic value/descriptor: 03 

real	0m0.075s
user	0m0.000s
sys	0m0.000s

Gattlib read_write

$ time ./examples/read_write/read_write DA:94:40:95:E0:87 read 0x2a38
Read UUID completed: 03 

real	0m0.994s
user	0m0.992s
sys	0m0.000s
$ time ./examples/read_write/read_write DA:94:40:95:E0:87 read 0x2a38
Read UUID completed: 03 

real	0m0.120s
user	0m0.116s
sys	0m0.000s
$ time ./examples/read_write/read_write DA:94:40:95:E0:87 read 0x2a38
Read UUID completed: 03 

real	0m0.109s
user	0m0.108s
sys	0m0.004s
$ time ./examples/read_write/read_write DA:94:40:95:E0:87 read 0x2a38
Read UUID completed: 03 

real	0m0.128s
user	0m0.124s
sys	0m0.000s

[ghost]

I am doing it on the Raspberry Pi 3, but I still get some very slow connection.

[mweal-ed]

I am having similar problems, and one thing I noticed while trying to debug the problem is that after a gattlib_disconnect the device is disconnected (it starts advertizing again), but bluez thinks it is still connected ("hcitool con" shows the device as still connected)

[mweal-ed]

Playing around some more, it looks like this problem has more to do with gattlib/bluez not properly disconnecting so when an attempt is made to re-connect, there is one of a couple (few?) different connection problems that can happen

[an01f01]

The code posted by @oliviermartin would not compile for me... but I noticed the main difference as why it works. It does not have to do with the async method or not (which the async is really nice to have). It has to do with the BDADDR_LE_RANDOM flag. The issue is that from my blueZ version 4.101 I can only connect to devices with the -t random parameter. I hope this solves the problems for everyone having the same issue! I changed the flag/parameter on the discover example and it work great. The ble_scan needs a bit more modifications for it to work right, but I have not need for it currently since I know the device address I want to connect to.

connection = gattlib_connect_async(NULL, argv[1], BDADDR_LE_RANDOM, BT_SEC_LOW, 0, 0, connect_cb);

Here is the main method on the updated read_write.c

`
uint8_t buffer[100];
int i, ret;
size_t len;
gatt_connection_t* connection;

if ((argc != 4) && (argc != 5)) {
	usage(argv);
	return 1;
}

if (strcmp(argv[2], "read") == 0) {
	g_operation = READ;
} else if ((strcmp(argv[2], "write") == 0) && (argc == 5)) {
	g_operation = WRITE;

	if ((strlen(argv[4]) >= 2) && (argv[4][0] == '0') && (argv[4][0] == 'x')) {
		value_data = strtol(argv[4], NULL, 0);
	} else {
		value_data = strtol(argv[4], NULL, 16);
	}
	printf("Value to write: 0x%lx\n", value_data);
} else {
	usage(argv);
	return 1;
}

if (gattlib_string_to_uuid(argv[3], strlen(argv[3]) + 1, &g_uuid) < 0) {
	usage(argv);
	return 1;
}

connection = gattlib_connect(NULL, argv[1], BDADDR_LE_RANDOM, BT_SEC_LOW, 0, 0);
if (connection == NULL) {
	fprintf(stderr, "Fail to connect to the bluetooth device.\n");
	return 1;
}

if (g_operation == READ) {
	len = sizeof(buffer);
	ret = gattlib_read_char_by_uuid(connection, &g_uuid, buffer, &len);
	assert(ret == 0);

	printf("Read UUID completed: ");
	for (i = 0; i < len; i++)
		printf("%02x ", buffer[i]);
	printf("\n");
} else {
	ret = gattlib_write_char_by_uuid(connection, &g_uuid, buffer, sizeof(buffer));
	assert(ret == 0);
}

gattlib_disconnect(connection);
return 0;

`