Bluetooth BLE Gatttool not working on repeat executions if used on script or python, but it works fine if used manually. (Raspberry Pi 4)
I'm smashing my head on the wall, because I can't understand why if I use a script, python or even single line command, only works on the first run and then it's unable to connect againt to the device on the followins executions.
Running on Raspberry Pi 4, with latest Raspberry OS and bluez stack.
Manual Execution
If I enter manually to gatttool interactive, works fine every single time.
pi@sp-pi002:~ $ sudo gatttool -i hci0 -b 02:10:32:20:00:AA -I <br>
[02:10:32:20:00:AA][LE]> connect <br>
Attempting to connect to 02:10:32:20:00:AA <br>
Connection successful <br>
[02:10:32:20:00:AA][LE]> char-write-req 0x0123 01126338221102234106DE <br>
Characteristic value was written successfully <br>
[02:10:32:20:00:AA][LE]> char-write-req 0x0123 0112633822110223410621 <br>
Characteristic value was written successfully <br>
[02:10:32:20:00:AA][LE]> disconnect <br>
[02:10:32:20:00:AA][LE]> exit <br>
pi@sp-pi002:~ $ <br>
"Pipelined" Execution
Very first time works OK, but the following nexts do not. Even if I try to do it manually after script execution, do not work.
pi@sp-pi002:~ $ (sleep 1; echo "connect"; sleep 4; echo "char-write-req 0x0123 01126338221102234106DE"; sleep 10; echo "char-write-req 0x0123 0112633822110223410621"; sleep 1; echo "disconnect"; sleep 1; echo "exit"; echo "sudo hciconfig hci0 reset") | sudo gatttool -i hci0 -b 02:10:32:20:00:AAA -I
[02:10:32:20:00:AA][LE]> connect
Attempting to connect to 02:10:32:20:00:AA
Connection successful
[02:10:32:20:00:AA][LE]> char-write-req 0x0123 01126338221102234106DE
Characteristic value was written successfully
[02:10:32:20:00:AA][LE]> char-write-req 0x0123 0112633822110223410621
Characteristic value was written successfully
[02:10:32:20:00:AA][LE]> disconnect
[02:10:32:20:00:AA][LE]> exit
pi@sp-pi002:~ $ (sleep 1; echo "connect"; sleep 4; echo "char-write-req 0x0123 01126338221102234106DE"; sleep 10; echo "char-write-req 0x0123 0112633822110223410621"; sleep 1; echo "disconnect"; sleep 1; echo "exit"; echo "sudo hciconfig hci0 reset") | sudo gatttool -i hci0 -b 02:10:32:20:00:AA -I
[02:10:32:20:00:AA][LE]> connect
Attempting to connect to 01:02:03:04:05:AA
[02:10:32:20:00:AA][LE]> char-write-req 0x0123 01126338221102234106DE
Command Failed: Disconnected
[02:10:32:20:00:AA][LE]> char-write-req 0x0123 0112633822110223410621
Command Failed: Disconnected
[02:10:32:20:00:AA][LE]> disconnect
[02:10:32:20:00:AA][LE]> exit
pi@sp-pi002:~ $
Pexpect in Python
Same as "Pipelined", very first time works OK, but the following nexts do not. Even if I try to do it manually after script execution, do not work.
import pexpect
import time
device_no = "hci0"
mac_str = "02:10:32:20:00:AA"
cmd = pexpect.spawn('sudo gatttool -i ' + device_no + ' -b ' + mac_str + ' -I')
cmd.expect('\[LE\]>')
cmd.sendline('connect')
cmd.expect('Connection successful')
cmd.sendline('char-write-req 0x0123 01126338221102234106DE')
cmd.expect('Characteristic value was written successfully')
time.sleep(10)
cmd.sendline('char-write-req 0x0123 0112633822110223410621')
cmd.expect('Characteristic value was written successfully')
cmd.sendline('disconnect')
cmd.expect('\[LE\]>')
cmd.sendline('exit')
Last words
I'm lost. I even tried using bluetoothctl instead gatttool on the scritps/python, but the result is always the same: works the very first time, and not the nexts ones (until BLE device reset the connection). I'm very confused why by doing the tasks manually works every simple times, but not with scripts. I'm not a pro on these topics, but also not a newbie. Any help will be aprecciated!
UPDATE 1
Bluez with D-bus API in Python
I still got same result as the other options (works at first try but not on the next ones)
import pydbus
from gi.repository import GLib
from time import sleep
dev_id = '02:10:32:20:00:AA'
lock_uuid = '0000acbff2-0000-1000-8000-00815ffb3wfb'
bluez_service = 'org.bluez'
adapter_path = '/org/bluez/hci0'
device_path = f"{adapter_path}/dev_{dev_id.replace(':', '_')}"
bus = pydbus.SystemBus()
adapter = bus.get(bluez_service, adapter_path)
device = bus.get(bluez_service, device_path)
device.Connect()
mngr = bus.get(bluez_service, '/')
def get_characteristic_path(dev_path, uuid):
mng_objs = mngr.GetManagedObjects()
for path in mng_objs:
chr_uuid = mng_objs[path].get('org.bluez.GattCharacteristic1', {}).get('UUID')
if path.startswith(dev_path) and chr_uuid == uuid:
return path
lock_uuid_path = get_characteristic_path(device._path, lock_uuid)
lock = bus.get(bluez_service, lock_uuid_path)
new_value = bytearray([0x01, 0x20, 0x60, 0x08, 0x02, 0x01, 0x02, 0x02, 0x01, 0x06, 0xDE])
lock.WriteValue(new_value, {})
sleep(10)
new_value = bytearray([0x01, 0x20, 0x60, 0x08, 0x02, 0x01, 0x02, 0x02, 0x01, 0x06, 0x21])
lock.WriteValue(new_value, {})
device.Disconnect()
bluetoothclt
First executions shows conections activity, the second one do not show any activity.
[bluetooth]#
[CHG] Device 02:10:32:20:00:AA Connected: yes
[CHG] Device 02:10:32:20:00:AA ServicesResolved: yes
[CHG] Device 02:10:32:20:00:AA ServicesResolved: no
[CHG] Device 02:10:32:20:00:AA Connected: no
[bluetooth]#
btmon
Some parts related to "LE Set Scan Enable" were deleted, to reduce lecture.
pi@sp-pi002:~ $ sudo btmon
Bluetooth monitor ver 5.50
= Note: Linux version 5.4.72-v7l+ (armv7l) 0.069236
= Note: Bluetooth subsystem version 2.22 0.069246
= New Index: DC:A6:32:0A:0D:AB (Primary,UART,hci0) [hci0] 0.069251
= Open Index: DC:A6:32:0A:0D:AB [hci0] 0.069255
= Index Info: DC:A6:32:0A:0D:AB (Cypress Semiconductor Corporation) [hci0] 0.069258
@ MGMT Open: bluetoothd (privileged) version 1.14 {0x0001} 0.069263
@ MGMT Open: btmon (privileged) version 1.14 {0x0002} 0.069757
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #1 [hci0] 19.298233
Type: Passive (0x00)
Interval: 60.000 msec (0x0060)
Window: 30.000 msec (0x0030)
Own address type: Public (0x00)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #2 [hci0] 19.298536
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #3 [hci0] 19.298580
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 #4 [hci0] 19.298942
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 40 #5 [hci0] 19.304392
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 02:10:32:20:00:AA (OUI 02-10-32)
Data length: 28
Company: CAEN RFID srl (170)
Data: 20321002
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Name (complete): Kino_BLE
16-bit Service UUIDs (partial): 1 entry
Unknown (0xf9f7)
TX power: 8 dBm
RSSI: -79 dBm (0xb1)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #6 [hci0] 19.304433
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #7 [hci0] 19.305665
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25 #8 [hci0] 19.305700
Scan interval: 60.000 msec (0x0060)
Scan window: 60.000 msec (0x0060)
Filter policy: White list is not used (0x00)
Peer address type: Public (0x00)
Peer address: 02:10:32:20:00:AA (OUI 02-10-32)
Own address type: Public (0x00)
Min connection interval: 20.00 msec (0x0010)
Max connection interval: 40.00 msec (0x0020)
Connection latency: 0 (0x0000)
Supervision timeout: 6000 msec (0x0258)
Min connection length: 0.000 msec (0x0000)
Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4 #9 [hci0] 19.306212
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 #10 [hci0] 19.413260
LE Connection Complete (0x01)
Status: Success (0x00)
Handle: 64
Role: Master (0x00)
Peer address type: Public (0x00)
Peer address: 02:10:32:20:00:AA (OUI 02-10-32)
Connection interval: 37.50 msec (0x001e)
Connection latency: 0 (0x0000)
Supervision timeout: 6000 msec (0x0258)
Master clock accuracy: 0x00
@ MGMT Event: Device Connected (0x000b) plen 41 {0x0002} [hci0] 19.413286
LE Address: 02:10:32:20:00:AA (OUI 02-10-32)
Flags: 0x00000000
Data length: 28
Company: CAEN RFID srl (170)
Data: 20321002
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Name (complete): Kino_BLE
16-bit Service UUIDs (partial): 1 entry
Unknown (0xf9f7)
TX power: 8 dBm
@ MGMT Event: Device Connected (0x000b) plen 41 {0x0001} [hci0] 19.413286
LE Address: 02:10:32:20:00:AA (OUI 02-10-32)
Flags: 0x00000000
Data length: 28
Company: CAEN RFID srl (170)
Data: 20321002
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Name (complete): Kino_BLE
16-bit Service UUIDs (partial): 1 entry
Unknown (0xf9f7)
TX power: 8 dBm
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2 #11 [hci0] 19.413395
Handle: 64
> HCI Event: Command Status (0x0f) plen 4 #12 [hci0] 19.415301
LE Read Remote Used Features (0x08|0x0016) ncmd 1
Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 14 #13 [hci0] 19.415306
LE Read Remote Used Features (0x08|0x0016) ncmd 1
Status: Success (0x00)
00 00 00 00 00 00 00 00 00 00 ..........
> ACL Data RX: Handle 64 flags 0x02 dlen 16 #14 [hci0] 19.505778
LE L2CAP: Connection Parameter Update Request (0x12) ident 1 len 8
Min interval: 16
Max interval: 32
Slave latency: 0
Timeout multiplier: 600
> HCI Event: LE Meta Event (0x3e) plen 12 #15 [hci0] 19.542823
LE Read Remote Used Features (0x04)
Status: Success (0x00)
Handle: 64
Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00
LE Encryption
< HCI Command: LE Start Encryption (0x08|0x0019) plen 28 #16 [hci0] 19.542873
Handle: 64
Random number: 0x94d43ce6d560a901
Encrypted diversifier: 0xed02
Long term key: d25d80004dd15ab09454000000000000
@ MGMT Event: New Connection Parameter (0x001c) plen 16 {0x0002} [hci0] 19.542899
Store hint: Reserved (0xaa)
LE Address: 01:02:10:32:20:00 (OUI 01-02-10)
Min connection interval: 16
Max connection interval: 32
Connection latency: 0 (0x0000)
Supervision timeout: 600
@ MGMT Event: New Connection Parameter (0x001c) plen 16 {0x0001} [hci0] 19.542899
Store hint: Reserved (0xaa)
LE Address: 01:02:10:32:20:00 (OUI 01-02-10)
Min connection interval: 16
Max connection interval: 32
Connection latency: 0 (0x0000)
Supervision timeout: 600
< ACL Data TX: Handle 64 flags 0x00 dlen 10 #17 [hci0] 19.542922
LE L2CAP: Connection Parameter Update Response (0x13) ident 1 len 2
Result: Connection Parameters accepted (0x0000)
> HCI Event: Command Status (0x0f) plen 4 #18 [hci0] 19.543653
LE Start Encryption (0x08|0x0019) ncmd 1
Status: Success (0x00)
< HCI Command: LE Connection Update (0x08|0x0013) plen 14 #19 [hci0] 19.543683
Handle: 64
Min connection interval: 20.00 msec (0x0010)
Max connection interval: 40.00 msec (0x0020)
Connection latency: 0 (0x0000)
Supervision timeout: 6000 msec (0x0258)
Min connection length: 0.000 msec (0x0000)
Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4 #20 [hci0] 19.544008
LE Connection Update (0x08|0x0013) ncmd 1
Status: Success (0x00)
> HCI Event: Encryption Change (0x08) plen 4 #21 [hci0] 19.842763
Status: Success (0x00)
Handle: 64
Encryption: Enabled with AES-CCM (0x01)
< HCI Command: Write Authenticated Payload Timeout (0x03|0x007c) plen 4 #22 [hci0] 19.842808
Handle: 64
Timeout: 30000 msec (0x0bb8)
< ACL Data TX: Handle 64 flags 0x00 dlen 7 #23 [hci0] 19.843152
ATT: Exchange MTU Request (0x02) len 2
Client RX MTU: 517
> HCI Event: Command Complete (0x0e) plen 6 #24 [hci0] 19.844110
Write Authenticated Payload Timeout (0x03|0x007c) ncmd 1
Status: Success (0x00)
Handle: 64
> HCI Event: Number of Completed Packets (0x13) plen 5 #25 [hci0] 19.955359
Num handles: 1
Handle: 64
Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7 #26 [hci0] 19.992707
ATT: Exchange MTU Response (0x03) len 2
Server RX MTU: 23
< ACL Data TX: Handle 64 flags 0x00 dlen 7 #27 [hci0] 19.993242
ATT: Read Request (0x0a) len 2
Handle: 0x0007
> ACL Data RX: Handle 64 flags 0x02 dlen 13 #28 [hci0] 20.067764
ATT: Read Response (0x0b) len 8
Value: 4b696e6f5f424c45
< ACL Data TX: Handle 64 flags 0x00 dlen 7 #29 [hci0] 20.068282
ATT: Read Request (0x0a) len 2
Handle: 0x0009
> HCI Event: Number of Completed Packets (0x13) plen 5 #30 [hci0] 20.105371
Num handles: 1
Handle: 64
Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7 #31 [hci0] 20.157731
ATT: Read Response (0x0b) len 2
Value: 0000
< ACL Data TX: Handle 64 flags 0x00 dlen 11 #32 [hci0] 20.158028
ATT: Read By Group Type Request (0x10) len 6
Handle range: 0x0001-0xffff
Attribute group type: Primary Service (0x2800)
> HCI Event: LE Meta Event (0x3e) plen 10 #33 [hci0] 20.158007
LE Connection Update Complete (0x03)
Status: Success (0x00)
Handle: 64
Connection interval: 37.50 msec (0x001e)
Connection latency: 0 (0x0000)
Supervision timeout: 6000 msec (0x0258)
> ACL Data RX: Handle 64 flags 0x02 dlen 24 #34 [hci0] 20.233300
ATT: Read By Group Type Response (0x11) len 19
Attribute data length: 6
Attribute group list: 3 entries
Handle range: 0x0001-0x0004
UUID: Generic Attribute Profile (0x1801)
Handle range: 0x0005-0x000b
UUID: Generic Access Profile (0x1800)
Handle range: 0x000c-0x0011
UUID: Unknown (0xf9f7)
< ACL Data TX: Handle 64 flags 0x00 dlen 11 #35 [hci0] 20.233587
ATT: Read By Group Type Request (0x10) len 6
Handle range: 0x0012-0xffff
Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5 #36 [hci0] 20.270400
Num handles: 1
Handle: 64
Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9 #37 [hci0] 20.307761
ATT: Error Response (0x01) len 4
Read By Group Type Request (0x10)
Handle: 0x0012
Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 64 flags 0x00 dlen 9 #38 [hci0] 20.321380
ATT: Write Request (0x12) len 4
Handle: 0x0004
Data: 0200
> ACL Data RX: Handle 64 flags 0x02 dlen 5 #39 [hci0] 20.382690
ATT: Write Response (0x13) len 0
< ACL Data TX: Handle 64 flags 0x00 dlen 18 #40 [hci0] 20.382970
ATT: Write Request (0x12) len 13
Handle: 0x0011
Data: 01106008000102000106de
> HCI Event: Number of Completed Packets (0x13) plen 5 #41 [hci0] 20.420453
Num handles: 1
Handle: 64
Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 5 #42 [hci0] 20.457713
ATT: Write Response (0x13) len 0
< ACL Data TX: Handle 64 flags 0x00 dlen 18 #43 [hci0] 30.974587
ATT: Write Request (0x12) len 13
Handle: 0x0011
Data: 0110600700010200010621
> ACL Data RX: Handle 64 flags 0x02 dlen 5 #44 [hci0] 31.032837
ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5 #45 [hci0] 31.147088
Num handles: 1
Handle: 64
Count: 1
@ MGMT Command: Disconnect (0x0014) plen 7 {0x0001} [hci0] 33.220115
LE Address: 02:10:32:20:00:AA (OUI 02-10-32)
< HCI Command: Disconnect (0x01|0x0006) plen 3 #46 [hci0] 33.220187
Handle: 64
Reason: Remote User Terminated Connection (0x13)
> HCI Event: Command Status (0x0f) plen 4 #47 [hci0] 33.221091
Disconnect (0x01|0x0006) ncmd 1
Status: Success (0x00)
> HCI Event: Disconnect Complete (0x05) plen 4 #48 [hci0] 33.245957
Status: Success (0x00)
Handle: 64
Reason: Connection Terminated By Local Host (0x16)
@ MGMT Event: Command Complete (0x0001) plen 10 {0x0001} [hci0] 33.246009
Disconnect (0x0014) plen 7
Status: Success (0x00)
LE Address: 02:10:32:20:00:AA (OUI 02-10-32)
@ MGMT Event: Device Disconnected (0x000c) plen 8 {0x0002} [hci0] 33.246030
LE Address: 02:10:32:20:00:AA (OUI 02-10-32)
Reason: Connection terminated by local host (0x02)
....................... END FIRST RUN OF SCRIPT.
....................... START OF SECOND EXECUTION.
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 #49 [hci0] 56.180508
Type: Passive (0x00)
Interval: 60.000 msec (0x0060)
Window: 30.000 msec (0x0030)
Own address type: Public (0x00)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #50 [hci0] 56.180811
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #51 [hci0] 56.180838
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 #52 [hci0] 56.181207
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 43 #53 [hci0] 56.204213
LE Advertising Report (0x02)
Num reports: 1
Event type: Non connectable undirected - ADV_NONCONN_IND (0x03)
Address type: Random (0x01)
Address: 0D:48:77:25:AE:79 (Non-Resolvable)
Data length: 31
Company: Microsoft (6)
Data: 01092002c67df605ed810a2e6f7e147cffa153daafbc76cd6c9459
RSSI: -77 dBm (0xb3)
...
...
... Many others LE Advertising Report (0x02)
...
...
> HCI Event: LE Meta Event (0x3e) plen 26 #76 [hci0] 89.682320
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: A4:83:E7:03:6E:75 (Apple, Inc.)
Data length: 14
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Company: Apple, Inc. (76)
Type: Unknown (16)
Data: 401c9671a8
RSSI: -91 dBm (0xa5)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #77 [hci0] 96.907783
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #78 [hci0] 96.908745
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
Bruno Gondell1 Answer
You can get more debug information by having bluetoothctl open in a different terminal. This will tell you what the Bluetooth daemon is doing as your scripts run.
service bluetooth status will often have errors in the information section at the bottom of the report.
Very low-level report information can be viewed with sudo btmon running in a separate terminal when running your scripts.
gatttool is one of the tools that has been deprecated by BlueZ.
And I don't believe that bluetoothctl was intended to be used in this way. The BlueZ developers frequently change bluetoothctl which will break your script if you get it working.
BlueZ provide a D-Bus API for programs to interact with the Bluetooth daemon.
https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/doc/adapter-api.txt
https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/doc/device-api.txt
https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/doc/gatt-api.txt
To use this API you will need to know:
The BlueZ D-Bus service is 'org.bluez'
The adapter device has the D-Bus object path of '/org/bluez/hci0' typically
The DBus interface for the adapter is 'org.bluez.Adapter1'
There is an example in the reply to the following question: https://raspberrypi.stackexchange.com/q/114150/121848
answered on Stack Overflow Nov 17, 2020 by 
ukBaz
ukBazUser contributions licensed under CC BY-SA 3.0