3.29.3: Crash on disconnect? Hard to repeat

[ojousima]

Under some circumstances the firmware crashes when NUS and GATT connection were disconnected. I am not sure about these circumstances. I assume it has the cause in the timing. Currently we are using pygatt to communicate with the sensor. Pygatt caused no crash of the firmware. But data transport seems not reliable for me using pygatt. So, I searched for alternatives. I was successful in using bleak to communicate with the sensor. But this causes a crash of the firmware when disconnecting. I found the cause in function calls from conn_params_init(). This function calls ble_conn_params_init() which calls app_timer_create(). app_timer_create() returns NRF_ERROR_INVALID_STATE if the timer is currently running. When this situation happens, the firmware crashes. I solved this by inserting ble_conn_params_stop() into conn_params_init(). Maybe you can check this issue. At the moment I did no test if this issue is also relevant for Ruuvi official firmware, but I think so.

[niksiboxi]

Connection tested with bluetoothctl CLI: Linux PC connects to the RuuviTag:

[bluetooth]# connect CC:5B:FE:FD:59:D2 
Attempting to connect to CC:5B:FE:FD:59:D2
[CHG] Device CC:5B:FE:FD:59:D2 Connected: yes
Connection successful
[CHG] Device CC:5B:FE:FD:59:D2 ServicesResolved: yes

No issues with disconnection either:

[Ruuvi 59D2]# disconnect CC:5B:FE:FD:59:D2 
Attempting to disconnect from CC:5B:FE:FD:59:D2
[CHG] Device CC:5B:FE:FD:59:D2 ServicesResolved: no
Successful disconnected
[CHG] Device CC:5B:FE:FD:59:D2 Connected: no

With GATTTOOL connections is successful when BLE addrress type is set to random:

sudo gatttool -t random -b CC:5B:FE:FD:59:D2 -I
[CC:5B:FE:FD:59:D2][LE]> connect
Attempting to connect to CC:5B:FE:FD:59:D2
Connection successful

With PYGATT connection and disconnection work in test.py:

import pygatt

ADDRESS = "CC:5B:FE:FD:59:D2"
ADDRESS_TYPE = pygatt.BLEAddressType.random

adapter = pygatt.GATTToolBackend()
adapter.start()

print('Connecting to device...')
try: 
    device = adapter.connect(ADDRESS, address_type = ADDRESS_TYPE)
    print('Connected')
except pygatt.exceptions.NotConnectedError:
    print('failed to connect')

try:
    device.disconnect()
    print('Disconnected')
except:
    print('failed to disconnect')

python test.py 
Connecting to device...
Connected
Disconnected

[ojousima]

Please see attached code. I flashed my tag with ruuvitag_b_armgcc_ruuvifw_test_v3.29.3_full.hex. When executing this code my tag reproduceable reboots after executing line 32.

#!/usr/bin/env python
# coding: utf-8
​
# https://bleak.readthedocs.io/en/latest/api.html
# https://pypi.org/project/bleak/
# https://github.com/hbldh/bleak
​
import asyncio
from binascii import hexlify
from bleak import BleakScanner
from bleak import BleakClient
​
loop = asyncio.get_event_loop()
​
address = "F2:23:D0:45:E4:DD"
​
​
UART_SRV = '6E400001-B5A3-F393-E0A9-E50E24DCCA9E'
UART_TX = '6E400002-B5A3-F393-E0A9-E50E24DCCA9E'
UART_RX = '6E400003-B5A3-F393-E0A9-E50E24DCCA9E'
​
​
def callback(sender: int, value: bytearray):
    print("Received %s" % hexlify(value))
​
​
async def listenEnvironment(address):
    async with BleakClient(address) as client:
        await client.start_notify(UART_RX, callback)
        await asyncio.sleep(1)
        await client.stop_notify(UART_RX)
        print("Stopped")
​
loop.run_until_complete(listenEnvironment(address))

When you change the time to wait in line 30 from 1 second to 10 seconds, Then the tag does not reboot.

[niksiboxi]

@ojousima Tested the code on my end with the same firmware.

• Reading RuuviTag's logs with JLinkRTTClient.
• Python version: 3.8.5
• Bleak version: 0.10.0

Log with await asyncio.sleep(1):

$ python3 gatt_connection.py 
Received b'0515302912c90c003c001403f0a1560805fa'
Received b'051530285bc90c003c001403eca1560805fb'
Received b'051530285bc90c003c001403eca1560805fc'
Received b'051530285bc90c0038001403eca1560805fd'
Received b'051530285bc90c003c001403eca1560805fe'
Received b'05153027c3c90c003c001c03eca1560805ff'
Stopped

Log with await asyncio.sleep(10):
$ python3 gatt_connection.py

Received b'05152f26d3c90c0038001803eca076090707'
Received b'05152f26aac90c003c001403eca076090708'
Received b'05152f26aac90c003c001403e4a076090709'
Received b'05152f26aac90c003c001403e8a07609070a'
Received b'05152f26aac90c0040001803e8a07609070c'
Received b'05152f2686c90c0038001403e0a07609070d'
Received b'05152f2686c90c0044001403e8a07609070e'
Received b'05152f2686c90c003c001403e8a07609070f'
Received b'05152f2686c90c003c001403f0a076090710'
Received b'05152f265cc90c003c001403e8a076090711'
Received b'05152f265cc90c0040001403e8a076090712'
Received b'05152f265cc90c003c002003eca076090713'
Received b'05152f265cc90c0040001803eca076090715'
Received b'05152f262ac90c0038001403e4a076090716'
Received b'05152f262ac90c0040001803eca076090717'
Received b'05152f262ac90c003c001c03f0a076090718'
Received b'05152f262ac90c003c001803e8a076090719'
Received b'05152f2631c90c0038001c03f0a07609071a'
Received b'05152f2631c90c0034001803e4a07609071b'
Received b'05152f2631c90c003c001403e4a07609071c'
Received b'05152f2631c90c0040001403e8a07609071d'
Received b'05152f2625c90c0040001c03e8a07609071e'
Received b'05152f2625c90c003c001803e4a07609071f'
Received b'05152f2625c90c003c001803f0a076090720'
Received b'05152f2625c90c0038001003eca076090721'
Received b'05152f2625c90c003c001803e8a076090722'
Received b'0515302636c90c003c001403f0a076090723'
Received b'0515302636c90c003c001803eca076090724'
Received b'0515302636c90c0040001803f4a076090727'
Received b'0515302636c90c0040001803eca076090728'
Received b'0515302636c90c003c002003e8a076090729'
Received b'0515302636c90c003c001803e8a07609072a'
Received b'0515302625c90c0040001403eca07609072b'
Received b'0515302625c90c003c001403eca07609072c'
Received b'0515302625c90c0038001803e8a07609072d'
Received b'0515302625c90c0038001803e8a07609072e'
Received b'0515302625c90c003c001403e8a07609072f'
Received b'051530260bc90c003c001803e4a076090730'
Received b'051530260bc90c003c001403eca076090731'
Received b'051530260bc90c003c001803eca076090732'
Received b'051530260bc90c0040001c03eca076090733'
Stopped

[ojousima]

Ok. I think there is some race condition, so let's leave this issue open for reference but mark as won't fix for now.

[DG12]

Thanks for providing all this detail.