LoPy stops detecting BLE advertisements

[papasmurph]

Product: LoPy
Firmware: 1.6 something (updated a few days ago)

My test code logs all detected iBeacons (that use BLE). After a seemingly arbitrary time, but after maybe around an hour or so, it no longer detects any beacons. After a reset it works again.

get_adv returns, yet with nothing, so it doesn't hang. I'm aware of the max length of 8 for the buffer, but there's plenty of slack, so it doesn't fill up.

It also seems it misses detections while it works: If I use a beacon that pings each second, it will detect such pings for a while, then stop for a few seconds, then do it again. Hopefully there's no filtering or time window used. The beacon is very close, so it's always well within -60 dBm. At the same time I have many beacons out of range.

I've just added a timeout for silence, that calls start_scan again (if now that will work), but at that time I might have missed out on several detections already.

I don't believe it's hardware related, considering it immediately works again after reboot, but who am I to say.

from network import Bluetooth
import pycom
import time

pycom.heartbeat(False)

bluetooth = Bluetooth()
bluetooth.start_scan(-1)

timeSleep = 0.05
timeout = 0

while True:
    pycom.rgbled(0x202020)
    time.sleep(timeSleep)
    device = bluetooth.get_adv()
    if device != None:
        timeout = 0
        d = [b for b in device.data]
        rssi = device.rssi
        if rssi > -60 and d[5] == 0x4c and d[6] == 0x00 and d[7] == 0x02 and d[8] == 0x15:
            majorid = d[25] * 256 + d[26]
            minorid = d[27] * 256 + d[28]
            power = d[29]

            pycom.rgbled(0x008000)
            time.sleep(0.10)
            print(str(rssi) + '/' + str(majorid) + '/' + str(minorid) + '/' + str(power))            
        else:
            pycom.rgbled(0x000020)
            print('!')
    else:
        pycom.rgbled(0x200000)
        print('?')

        timeout += timeSleep + timeSleep
        if timeout > 10:
            bluetooth.start_scan(-1)
            timeout = 0

    time.sleep(timeSleep)

[tudro]

My lopy4 arrived and i tested with it, too, although i was pretty sure it wouldn't make a difference. It didn't, it does the same thing.

I left my lopy running since yesterday noon and from 270 readings, 223 were correct. So that's around 17-18% loss.

[tudro]

Hello,

I'm having the same problems with reading the BT advs. My setup is a lopy with a deepsleep shield and 3 ruuvi tags that adv every second. The ruuvis are placed about 3 meters apart. The lopy is on 1.17.0.b1.

The process is: read BT data, go to deepsleep for 15 sec, wake up, read BT data, deepsleep, etc.

I have tried first with the BT example in the pycom docs. The scan was set to 20 seconds. In about 40% of the cases the lopy would not read the data from all the 3 ruuvis.

Then i tried with the deinit/init. Scan for 10 sec, if not all 3 ruuvis read, deinit/init, scan for another 10 sec. It reduced the loss to only about 10%.

In the real case the deepsleep interval will be 1 hour. So, if it doesn't read all the ruuvis, some results will be 2 hours apart or even more, depending on luck, i guess :)

Is there any plan or update on this problem?

Thank you

[duffo64]

@jcaron Hi,

only the firmware :-)
I did not touch anything in my code because I was pretty sure it was working as is.
Now I am patiently waiting for the death (hope not) of two WiPy 3 with the very latest firmware that are running since 47 hours.

[jcaron]

Hi @duffo64,

Can you clarify what was the change that made the difference in the end?

[duffo64]

Yet another update:

This is a WiPy 1.0 with a not-so-recent firmware. Running since two weeks and counting. BLE, WiFi and MQTT are running without hiccups :D

{"ts":1517336479,"pmac":"24xxxxxxxxxx","up":1302802,"fw":"1.12.0.b1","ip":"192.168.0.111"}

[livius]

@duffo64
good finding on github.
I saw this kind of assert on the forum.

[duffo64]

Follow up:

I restarted both WiPy 3 giving them another chance without modifying code at all, and this time was better: more than 24 hours of normal behavior without reboots or BLE lockups. Still, BLE acts randomly in the long run.
BTW there is an IDF related issue on Github that could lead to weird results on the BLE side, as I read.

[duffo64]

@livius Hi,

Been there, done that. Unfortunately the culprit is not does not seem lack of memory (one WiPy3 still working, the other went south like all WiPy 2).
Anyway, I have collection in code as soon as a ble scan cycle ends.

[livius]

@duffo64
If it survived only on wipy3, this can point me that memory is here problem (only guess).
Did you tried track it down and print gc.mem_free() in the code to see memory consumption?
And do you have gc.collect() in the code or you have enabled automatic garbage collector?

[duffo64]

@alanm101
Despite my initial enthusiasm, I must say that the situation is slightly better using 1.10.2.b1. Basically I had two issues:

• my beacons were not recognized, and this is solved
• callback for advertisements stops firing after a while, but I know that the program is not frozen somewhere. This still unsolved

The very same script is loaded on four WiPy 2.0, two WiPy 3.0 and one LoPy. Only one WiPy 3.0 survived after 18 hours. Sigh.

[alanm101]

Thanks! I will test this weekend.

[duffo64]

Wow...

On 1.10.1.b1 it's really, really, really better !

...did I say "really" ?

[duffo64]

@alanm101
This is a small Arduino sketch on ESP32 Thing (Sparkfun) running without a glitch since this morning.
Moreover, it's happily seeing even my EMBC02 beacons. So, should I presume that in the end it's a micropython issue ?

[alanm101]

@jmarcelino This hack is working for me so far. If I don't detect a BLE event within 10 seconds, I machine.reset().

from network import Bluetooth
import machine
import time
import binascii
import gc

beaconlist = ['d3e0f6cd4ca9','e9f1db4814ef']
beaconevents = []
timelastdata = time.time()

def new_adv_event(event):
    global beaconlist, beaconevents, timelastdata
    if event.events() == Bluetooth.NEW_ADV_EVENT:
        anydata = True
        while anydata:
            adv = bluetooth.get_adv()
            if adv != None:
                timelastdata = time.time()
                devid = binascii.hexlify(adv[0]).decode('utf-8')
                rssi = str(adv[3]*-1)
                if devid in beaconlist:
                    if len(beaconevents) > 5:
                        beaconevents.pop(0)
                    beaconevents.append([devid, rssi])  
            else:
                anydata = False

print('Starting BLE scan')
bluetooth = Bluetooth()
bluetooth.callback(trigger = Bluetooth.NEW_ADV_EVENT, handler = new_adv_event)
bluetooth.init()
bluetooth.start_scan(-1)

cycles = 0
p_in = machine.Pin('G17',machine.Pin.IN, pull=machine.Pin.PULL_UP)

while True:
    if p_in() == 0:
        print('pin')
        bluetooth.stop_scan()
        break

    cycles += 1
    # Run garbage collector every 20 cycles.
    if cycles%20 == 0:
        gc.collect()
    # If no BLE event for 10 seconds, hard reset
    if time.time() - timelastdata > 10:
        machine.reset()

[jmarcelino]

@alanm101
Starting on it tonight! I got this to be partially funded by my current client so I’ll have more time for it :)

[alanm101]

@jmarcelino Hi. Have you had a chance to work on this?

Regards,
Alan.

[alanm101]

I'm no longer convinced that this is a Lopy/uPython issue. I hacked raw C code and ran on a generic ESP32 using newly acquired knowledge. The code failed. It could be my hacks were wrong or perhaps the ESP32 or the IDF is screwed. I'm now trying new uPython code on the Lopy.

[alanm101]

Test1: Single beacon using ESP32 at one second intervals.

Changes to ble_adv/main/app_bt.c
Lines 157-158:
uint16_t adv_intv_min = 256x3; // 160ms
uint16_t adv_intv_max = 256x3; // 160ms

<The 'x' is replaced with an asterisk. Some issue with uploading.>

Result: 2 hours with no problems.

Test2: Single beacon using ESP32 at one second intervals.

Changes to ble_adv/main/app_bt.c
Lines 157-158:
uint16_t adv_intv_min = 256x2; // 160ms
uint16_t adv_intv_max = 256x2; // 160ms

<The 'x' is replaced with an asterisk. Some issue with uploading.>

Result: 50 minutes, advs no longer detected.

[alanm101]

@alanm101 My ignorance knows no bounds. The adv is broadcast on 3 channels, hence the multiple events per broadcast. My new tests are <cough> compensating for that.