Skip to content

Non-blocking NimBLEScan stops calling callback after random number of scans #308

@ab0oo

Description

@ab0oo

I'm struggling to put into words what I'm seeing, but here's my best attempt.
I'm writing a simply BLE scanner that uses callbacks, based on the example code. I've made it as simple as possible, but it's not acting the way I'd expect.

The code:

#include "NimBLEDevice.h"

NimBLEScan* pBLEScan;
long lastUpdate;
const int scanTime = 3;

class MyAdvertisedDeviceCallbacks: public NimBLEAdvertisedDeviceCallbacks {
    void onResult(NimBLEAdvertisedDevice* advertisedDevice) {
      Serial.printf("Advertised Device: %s \n", advertisedDevice->toString().c_str());
    }
};

void setup() {
  Serial.begin(115200);
  BLEDevice::init("");
  pBLEScan = BLEDevice::getScan(); //create new scan
  pBLEScan->setAdvertisedDeviceCallbacks(new MyAdvertisedDeviceCallbacks());
  pBLEScan->setActiveScan(true); //active scan uses more power, but get results faster
  pBLEScan->setInterval(97);
  pBLEScan->setWindow(37); // less or equal setInterval value
  pBLEScan->setMaxResults(0);
}

void loop() {
  long now = millis();
  if ( now >= lastUpdate + 1000 ) {
    Serial.printf("Tick: %ld\n", now / 1000 );
    lastUpdate = now;
  }
  BLEScanResults foundDevices = pBLEScan->start(scanTime, false);
  pBLEScan->clearResults(); // delete results fromBLEScan buffer to release memory
}

What I want to see is "Advertised Device: XXX" information printed periodically, as devices are discovered. I'd also like to see the word "Tick" posted every second, indicating that the scan is non-blocking and happening "in the background" while my main loop() continues to work.
In this case, it seems that the pBLEScan->start() is blocking, and since my scanTime is 3 seconds, I see "Tick 3" ... "Tick 6" ... "Tick 9"... and then... nothing. The output looks like this:

15:26:53.409 -> ets Jun 8 2016 00:22:57
15:26:53.409 ->
15:26:53.409 -> rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
15:26:53.409 -> configsip: 0, SPIWP:0xee
15:26:53.409 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
15:26:53.409 -> mode:DIO, clock div:1
15:26:53.409 -> load:0x3fff0030,len:1420
15:26:53.409 -> ho 0 tail 12 room 4
15:26:53.409 -> load:0x40078000,len:13540
15:26:53.409 -> load:0x40080400,len:3604
15:26:53.409 -> entry 0x400805f0
15:26:54.044 -> Advertised Device: Name: 846B215F5FC233AEE9, Address: f3:33:c0:55:58:95, appearance: 0, manufacturer data: a705051001000000000000001b00ca, serviceUUID: 0xfe07, txPower: 0
15:26:54.508 -> Advertised Device: Name: , Address: 75:6d:2b:0e:f5:29, manufacturer data: 4c001006191e23cfe2c1, txPower: 8
15:26:55.115 -> Advertised Device: Name: , Address: 76:90:c3:e9:90:02, manufacturer data: e00001b9ca72c54c, serviceUUID: 0xfe9f
15:26:55.115 -> Service Data:
15:26:55.115 -> UUID: 0xfe9f, Data: �nTF065F6mZs
15:26:55.115 -> Advertised Device: Name: , Address: 43:16:54:3d:42:ed, manufacturer data: 4c001005491c18dbfe
15:26:55.221 -> Advertised Device: Name: , Address: d7:96:ba:2b:33:e2, manufacturer data: 4c0012020000
15:26:56.187 -> Advertised Device: Name: , Address: 5d:0c:66:6f:61:2e, manufacturer data: 4c00021561b5c6c7bc4249c982cc3fc6832f69ae00640001a6
15:26:56.664 -> Advertised Device: Name: , Address: 5a:35:34:88:dc:8a, serviceUUID: 0xfd6f
15:26:56.664 -> Service Data:
15:26:56.664 -> UUID: 0xfd6f, Data: ⸮<⸮�
15:26:56.912 -> Advertised Device: Name: , Address: 4b:21:d4:48:87:b6, serviceUUID: 0xfe9f
15:26:56.912 -> Service Data:
15:26:56.912 -> UUID: 0xfe9f, Data:
> 15:26:56.912 -> Tick: 3
15:26:56.950 -> Advertised Device: Name: , Address: 43:16:54:3d:42:ed, manufacturer data: 4c001005491c18dbfe
15:26:56.950 -> Advertised Device: Name: , Address: 5a:35:34:88:dc:8a, serviceUUID: 0xfd6f
15:26:56.950 -> Service Data:
15:26:56.950 -> UUID: 0xfd6f, Data: ⸮<⸮�
15:26:58.214 -> Advertised Device: Name: , Address: 76:90:c3:e9:90:02, manufacturer data: e00001b9ca72c54c, serviceUUID: 0xfe9f
15:26:58.214 -> Service Data:
15:26:58.214 -> UUID: 0xfe9f, Data: �nTF065F6mZs
15:26:59.290 -> Advertised Device: Name: , Address: 5d:0c:66:6f:61:2e, manufacturer data: 4c00021561b5c6c7bc4249c982cc3fc6832f69ae00640001a6
15:26:59.928 -> Advertised Device: Name: , Address: 75:6d:2b:0e:f5:29, manufacturer data: 4c001006191e23cfe2c1, txPower: 8
15:26:59.928 -> Advertised Device: Name: , Address: f3:33:c0:55:58:95, appearance: 0, manufacturer data: a705051001000000000000001b00ca, serviceUUID: 0xfe07, txPower: 0
> 15:26:59.964 -> Tick: 6
15:27:00.073 -> Advertised Device: Name: , Address: 43:16:54:3d:42:ed, manufacturer data: 4c001005491c18dbfe
15:27:00.682 -> Advertised Device: Name: , Address: 5a:35:34:88:dc:8a, serviceUUID: 0xfd6f
15:27:00.682 -> Service Data:
15:27:00.682 -> UUID: 0xfd6f, Data: ⸮<⸮�
15:27:01.043 -> Advertised Device: Name: , Address: 76:90:c3:e9:90:02, manufacturer data: e00001b9ca72c54c, serviceUUID: 0xfe9f
15:27:01.077 -> Service Data:
15:27:01.077 -> UUID: 0xfe9f, Data: �nTF065F6mZs
15:27:01.328 -> Advertised Device: Name: , Address: 5d:0c:66:6f:61:2e, manufacturer data: 4c00021561b5c6c7bc4249c982cc3fc6832f69ae00640001a6
15:27:02.952 -> Advertised Device: Name: , Address: f3:33:c0:55:58:95, appearance: 0, manufacturer data: a705051001000000000000001b00ca, serviceUUID: 0xfe07, txPower: 0
15:27:02.952 -> Advertised Device: Name: , Address: 75:6d:2b:0e:f5:29, manufacturer data: 4c001006191e23cfe2c1, txPower: 8
> 15:27:02.988 -> Tick: 9
15:27:02.988 -> Advertised Device: Name: , Address: 43:16:54:3d:42:ed, manufacturer data: 4c001005491c18dbfe
15:27:03.388 -> Advertised Device: Name: , Address: 5d:0c:66:6f:61:2e, manufacturer data: 4c00021561b5c6c7bc4249c982cc3fc6832f69ae00640001a6
15:27:04.965 -> Advertised Device: Name: , Address: 5a:35:34:88:dc:8a, serviceUUID: 0xfd6f
15:27:04.965 -> Service Data:
15:27:04.965 -> UUID: 0xfd6f, Data: ⸮<⸮�
15:27:05.430 -> Advertised Device: Name: , Address: 76:90:c3:e9:90:02, manufacturer data: e00001b9ca72c54c, serviceUUID: 0xfe9f
15:27:05.430 -> Service Data:
15:27:05.430 -> UUID: 0xfe9f, Data: �nTF065F6mZs
15:27:05.430 -> Advertised Device: Name: 846B215F5FC233AEE9, Address: f3:33:c0:55:58:95, appearance: 0, manufacturer data: a705051001000000000000001b00ca, serviceUUID: 0xfe07, txPower: 0
15:27:09.114 -> Advertised Device: Name: , Address: 75:6d:2b:0e:f5:29, manufacturer data: 4c001006191e23cfe2c1, txPower: 8
15:27:17.923 -> Advertised Device: Name: , Address: 7e:d5:fc:b0:9c:b5, manufacturer data: 4c00021561b5c6c7bc4249c982cc3fc6832f69ae00640001a6
15:27:35.274 -> Advertised Device: Name: , Address: d7:96:ba:2b:33:e2, manufacturer data: 4c0012020000
15:27:38.533 -> Advertised Device: Name: PROV_005d13Z, Address: 24:62:ab:e2:16:ee, serviceUUID: 0000ffff-0000-1000-8000-00805f9b34fb
15:27:49.808 -> Advertised Device: Name: , Address: 86:2a:fd:a8:50:c6, manufacturer data: 650001c905, serviceUUID: 0xfe78
15:27:49.808 -> Service Data:
15:27:49.808 -> UUID: 0xfdf7, Data: �⸮X⸮⸮⸮⸮V⸮⸮ziEfs�5
15:27:54.071 -> Advertised Device: Name: , Address: 43:16:54:3d:42:ed, manufacturer data: 4c001005491c18dbfe
15:27:54.360 -> Advertised Device: Name: , Address: 76:90:c3:e9:90:02, manufacturer data: e00001b9ca72c54c, serviceUUID: 0xfe9f
15:27:54.360 -> Service Data:
15:27:54.360 -> UUID: 0xfe9f, Data: �nTF065F6mZs
15:27:55.217 -> Advertised Device: Name: , Address: 7e:d5:fc:b0:9c:b5, manufacturer data: 4c00021561b5c6c7bc4249c982cc3fc6832f69ae00640001a6
15:27:57.163 -> Advertised Device: Name: PROV_005d13Z, Address: 24:62:ab:e2:16:ee, serviceUUID: 0000ffff-0000-1000-8000-00805f9b34fb
15:28:00.645 -> Advertised Device: Name: 846B215F5FC233AEE9, Address: f3:33:c0:55:58:95, appearance: 0, manufacturer data: a705051001000000000000001b00ca, serviceUUID: 0xfe07, txPower: 0
15:28:06.468 -> Advertised Device: Name: , Address: 75:6d:2b:0e:f5:29, manufacturer data: 4c001006191e23cfe2c1, txPower: 8
15:28:09.374 -> Advertised Device: Name: , Address: d7:96:ba:2b:33:e2, manufacturer data: 4c0012020000
15:28:09.661 -> Advertised Device: Name: , Address: 4b:21:d4:48:87:b6, manufacturer data: e00001f2ca849dc4, serviceUUID: 0xfe9f
15:28:09.661 -> Service Data:
15:28:09.661 -> UUID: 0xfe9f, Data:

Reading through that, you see I get a "tick" at 15:26:56.912, at 15:26:59.964, 15:27:02.988, and ... never again for the next 60+ seconds. The scan appears to continue to run, but my main loop() just... disappears.
Questions:

  • where is executing disappearing to, that my simple little loop() stops looping?
  • am I unrealistic in thinking there's a way to scan and continue to process at the same time. Even with the callback, the scan appears to block execution of the main loop

BTW, I don't think this is a "bug" or "issue", but I couldn't find a more appropriate forum to ask this question. If there is one, let me know and I'll move there. Thanks!

John

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions