Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Sometimes startPeripheralScan doesn't return any result #480

Closed
fpabl0 opened this issue Jun 20, 2020 · 24 comments · Fixed by #490
Closed

Sometimes startPeripheralScan doesn't return any result #480

fpabl0 opened this issue Jun 20, 2020 · 24 comments · Fixed by #490
Labels
Android bug Something isn't working

Comments

@fpabl0
Copy link

fpabl0 commented Jun 20, 2020

Hi!
I am using your library for a personal project. The problem I have is that when I try to scan many times, the function startPeripheralScan doesn't return anything, or some devices aren't shown. Here is my code:

  void startScan() {
      _devicesList.clear();
      _devicesSink.add(null);
      _scanSubscription = _bleManager
         .startPeripheralScan(scanMode: ScanMode.balanced, allowDuplicates: false)
         .listen((device) {
             // exclude duplicated devices
             for (var d in _devicesList) {
                 if (device.peripheral.identifier == d.peripheral.identifier) return;
             }
             _devicesList.add(device);
            _devicesSink.add(_devicesList.sublist(0));
      });
      _timeoutTimer = new Timer(const Duration(seconds: 5), () => stopScan());
   }

   // Stop BLE devices scan
  Future<void> stopScan() async {
     _timeoutTimer?.cancel();
     if (_devicesList.length == 0) {
       _devicesSink.add([]);
     }
     await _scanSubscription?.cancel();
     await _bleManager?.stopPeripheralScan();
  }
@mikolak
Copy link
Collaborator

mikolak commented Jun 21, 2020

Hi!

Could you set logs to verbose, run the application from native IDE (XCode or Android Studio, but Android project, not Flutter) and check the logs? Could you paste them if that didn't give you an idea as to what happened?

@fpabl0
Copy link
Author

fpabl0 commented Jun 21, 2020

Yes, ok this is log when it discovers all the devices:

2020-06-21 10:04:01.311 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: startDeviceScan
2020-06-21 10:04:01.337 10474-10789/com.example.otter_feeder D/BluetoothAdapter: isLeEnabled(): ON
2020-06-21 10:04:01.337 10474-10789/com.example.otter_feeder E/CheckPermission: _bluetooth code = 10 
2020-06-21 10:04:01.344 2600-3048/? I/bt_stack: [INFO:gatt_api.cc(1006)] GATT_Register
2020-06-21 10:04:01.344 2600-3048/? I/bt_stack: [INFO:gatt_api.cc(1029)] allocated gatt_if=5
2020-06-21 10:04:01.348 10474-10496/com.example.otter_feeder D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=5 mScannerId=0
2020-06-21 10:04:01.354 2600-3016/? D/BtGatt.CustomScanStrategy: checkAndNofifyScanManager bConcession =false
2020-06-21 10:04:01.354 2600-3016/? D/BtGatt.CustomScanStrategy: bOshareTransfering = false bGameSpace = false bWIFIHeavyTraffic = false
2020-06-21 10:04:01.364 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.364 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.364 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.365 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.366 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.367 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.367 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.367 2600-3016/? D/BtGatt.CustomScanStrategy: CustomScanStrategy startWatchWIFITraffic need reduce for wifi heavy traffic
2020-06-21 10:04:01.367 2600-3016/? D/BtGatt.CustomScanStrategy: MonitorThread wlan0
2020-06-21 10:04:01.368 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.368 2600-3016/? D/BtGatt.ScanManager: startWatchWIFITraffic
2020-06-21 10:04:01.368 2600-3016/? D/BtGatt.CustomScanStrategy: getCurrAction: 0
2020-06-21 10:04:01.369 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.369 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.370 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.370 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.372 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.373 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.373 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.373 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.375 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.376 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.376 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.376 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.377 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.377 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.378 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.378 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.379 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.379 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.380 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.380 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.384 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.384 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.384 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.384 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.399 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.399 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.399 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.399 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.399 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.400 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.400 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.400 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.415 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:01.418 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:01.580 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.581 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.581 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.582 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.582 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.582 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.582 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.583 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.587 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:01.597 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.597 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.597 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.597 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.602 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:01.605 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:01.606 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.606 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.607 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.607 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.613 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:01.615 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:01.943 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.943 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.944 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.944 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.944 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:01.945 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:01.945 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:01.945 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:01.950 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:02.012 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.013 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.014 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.014 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.014 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.015 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.016 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.016 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.016 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.017 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.017 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.018 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.025 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:02.028 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:02.445 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.446 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.447 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.447 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.491 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.492 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.492 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.493 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.493 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.494 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.494 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.494 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.494 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.495 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.495 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.495 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.499 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:02.510 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:02.657 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.657 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.658 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.658 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.665 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:02.963 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:02.964 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:02.964 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:02.964 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:02.968 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:03.099 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.100 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.100 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.101 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.101 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.102 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.102 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.102 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.102 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.103 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.103 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.107 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.108 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:03.138 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.138 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.139 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.139 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.143 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:03.164 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.165 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.165 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.166 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.171 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:03.193 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:04:03.217 10474-10484/com.example.otter_feeder I/zygote64: Do partial code cache collection, code=30KB, data=27KB
2020-06-21 10:04:03.217 10474-10484/com.example.otter_feeder I/zygote64: After code cache collection, code=30KB, data=27KB
2020-06-21 10:04:03.217 10474-10484/com.example.otter_feeder I/zygote64: Increasing code cache capacity to 128KB
2020-06-21 10:04:03.493 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.493 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.494 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.494 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.498 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:03.592 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.593 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.594 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.595 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.595 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.595 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.596 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.596 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.599 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:03.602 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.603 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.603 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.603 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.607 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:03.644 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.645 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.645 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.646 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.646 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.646 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.647 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.647 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.647 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.647 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.648 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.648 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.653 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:03.957 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.958 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.958 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.958 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.958 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:03.959 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:03.959 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:03.959 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:03.963 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.081 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:04:04.081 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 10:04:04.189 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.190 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.190 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.191 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.191 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.191 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.191 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.192 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.196 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.234 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.234 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.234 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.235 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.241 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.329 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.330 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.330 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.330 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.331 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.331 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.331 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.331 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.339 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.339 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.340 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.340 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.340 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.355 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.371 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.373 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.374 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.374 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.379 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.715 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.716 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.716 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.717 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.717 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.718 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.718 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.719 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.728 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.729 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.730 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.730 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.731 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.731 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.731 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.731 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.732 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.732 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.742 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.764 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.765 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.765 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.765 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.771 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.865 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.865 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.865 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.865 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.869 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:04.881 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.885 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.886 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.887 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.887 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:04.887 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:04.887 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:04.887 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:04.892 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:05.386 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:05.387 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:05.387 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:05.388 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:05.701 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:05.701 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:05.701 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:05.702 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:05.708 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:05.910 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:05.910 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:05.911 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:05.911 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:05.912 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:05.913 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:05.913 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:05.914 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:05.916 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:05.922 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:06.220 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:06.221 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:06.221 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:06.221 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:06.228 2600-2616/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 10:04:06.346 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: stopDeviceScan
2020-06-21 10:04:06.351 10474-10789/com.example.otter_feeder D/BluetoothAdapter: isLeEnabled(): ON
2020-06-21 10:04:06.360 2600-3016/? D/BtGatt.CustomScanStrategy: CustomScanStrategy stopWatchWIFITraffic
2020-06-21 10:04:06.361 2600-10790/? D/BtGatt.CustomScanStrategy: interupted
2020-06-21 10:04:06.361 2600-10790/? D/BtGatt.CustomScanStrategy: MonitorThread exit
2020-06-21 10:04:06.361 2600-3016/? D/BtGatt.ScanManager: stopWatchWIFITraffic
2020-06-21 10:04:06.363 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:06.363 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:06.363 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:06.363 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:06.367 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:06.367 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:06.367 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:06.367 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:04:06.369 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:04:06.369 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:04:06.369 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:04:06.369 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--

And this is the log, when no devices are found:

2020-06-21 10:07:39.256 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: startDeviceScan
2020-06-21 10:07:39.353 10474-10474/com.example.otter_feeder I/Choreographer: Skipped 5 frames!  The application may be doing too much work on its main thread.
2020-06-21 10:07:43.227 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:07:44.236 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:07:44.236 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 10:07:44.263 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: stopDeviceScan
2020-06-21 10:07:47.228 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:07:49.360 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:07:49.360 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 10:07:51.229 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:07:54.481 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:07:54.481 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged

This log is the same case as above:

2020-06-21 10:11:24.873 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 10:11:24.873 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 10:11:24.873 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:11:24.873 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:11:27.136 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: startDeviceScan
2020-06-21 10:11:27.262 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:11:29.522 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:11:29.522 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 10:11:31.264 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:11:32.148 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: stopDeviceScan
2020-06-21 10:11:35.264 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:11:37.200 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:11:37.200 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged

Here is the log when no devices are returned twice in a row:

2020-06-21 10:21:40.543 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 10:21:40.543 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 10:21:43.329 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: startDeviceScan
2020-06-21 10:21:43.353 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:21:43.916 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:21:43.916 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 10:21:47.358 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:21:48.342 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: stopDeviceScan
2020-06-21 10:21:49.033 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:21:49.033 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 10:21:50.236 1919-11713/? D/libc-netbsd: [getaddrinfo]:  hostname=www.google.com;  servname=(null);  app_pid=1919;  app_uid=1000;  ai_flags=1024;  ai_family=0; ai_socktype=1 from prox result 0
2020-06-21 10:21:50.236 1919-11712/? D/libc-netbsd: [getaddrinfo]:  hostname=connectivitycheck.gstatic.com;  servname=(null);  app_pid=1919;  app_uid=1000;  ai_flags=1024;  ai_family=0; ai_socktype=1 from prox result 0
2020-06-21 10:21:51.358 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:21:54.154 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:21:54.154 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 10:21:55.196 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: startDeviceScan
2020-06-21 10:21:55.320 7470-7498/? I/Finsky: [155] kqp.run(3): Stats for Executor: BlockingExecutor kso@d494430[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 48]
2020-06-21 10:21:55.323 7470-7498/? I/Finsky: [155] kqp.run(3): Stats for Executor: LightweightExecutor kso@818d8a9[Running, pool size = 4, active threads = 0, queued tasks = 0, completed tasks = 572]
2020-06-21 10:21:55.356 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:21:56.029 7470-7498/? I/Finsky: [155] kqp.run(3): Stats for Executor: bgExecutor kso@4dee2e[Running, pool size = 4, active threads = 0, queued tasks = 0, completed tasks = 1429]
2020-06-21 10:21:59.359 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:22:00.209 10474-10474/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: stopDeviceScan
2020-06-21 10:22:03.361 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:22:04.396 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:22:04.396 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 10:22:04.514 3063-3111/? I/QcrilOemhookMsgTunnel: [0]processOemHookIndication length=21
2020-06-21 10:22:04.515 3063-3063/? D/QcrilMsgTunnelIfaceManager: handleMessage what = 0
2020-06-21 10:22:07.359 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:22:11.361 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 10:22:11.873 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 10:22:11.873 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged

I'm using your last library version and Flutter 1.17.4.

@mikolak
Copy link
Collaborator

mikolak commented Jun 21, 2020

Did you do BleManager().setLogLevel(LogLevel.verbose)? (something like that, don't remember the API right now)

@fpabl0
Copy link
Author

fpabl0 commented Jun 21, 2020

Yes, here:

  final _bleManager = new BleManager();
  ...
  // Init bluetooth
  Future<void> _init() async {
      _bleManager.setLogLevel(LogLevel.verbose);
      await _bleManager.createClient();
      await _checkPermissions();
      await _waitForBluetoothPoweredOn();
  }

@mikolak
Copy link
Collaborator

mikolak commented Jun 21, 2020

It has to be called after .createClient(). Can you change the order of calls and take a look at the logs again?

@fpabl0
Copy link
Author

fpabl0 commented Jun 21, 2020

Yes, I can. I got this log when the scan returns three devices instead of four expected:

2020-06-21 15:19:33.954 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 15:19:35.200 23449-23449/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: startDeviceScan
2020-06-21 15:19:35.208 23449-23449/com.example.otter_feeder D/RxBle#ClientOperationQueue: QUEUED   ScanOperationApi21(116670761)
2020-06-21 15:19:35.211 23449-23603/com.example.otter_feeder D/RxBle#ClientOperationQueue: STARTED  ScanOperationApi21(116670761)
2020-06-21 15:19:35.213 23449-23615/com.example.otter_feeder I/RxBle#QueueOperation: Scan operation is requested to start.
2020-06-21 15:19:35.215 23449-23615/com.example.otter_feeder D/BluetoothAdapter: isLeEnabled(): ON
2020-06-21 15:19:35.215 23449-23615/com.example.otter_feeder E/CheckPermission: _bluetooth code = 10 
2020-06-21 15:19:35.219 2600-3048/? I/bt_stack: [INFO:gatt_api.cc(1006)] GATT_Register
2020-06-21 15:19:35.220 2600-3048/? I/bt_stack: [INFO:gatt_api.cc(1029)] allocated gatt_if=5
2020-06-21 15:19:35.220 23449-23626/com.example.otter_feeder D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=5 mScannerId=0
2020-06-21 15:19:35.228 2600-3016/? D/BtGatt.CustomScanStrategy: checkAndNofifyScanManager bConcession =false
2020-06-21 15:19:35.228 2600-3016/? D/BtGatt.CustomScanStrategy: bOshareTransfering = false bGameSpace = false bWIFIHeavyTraffic = false
2020-06-21 15:19:35.228 23449-23603/com.example.otter_feeder D/RxBle#ClientOperationQueue: FINISHED ScanOperationApi21(116670761) in 18 ms
2020-06-21 15:19:35.235 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.235 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.235 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.236 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.240 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.240 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.240 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.240 2600-3016/? D/BtGatt.CustomScanStrategy: CustomScanStrategy startWatchWIFITraffic need reduce for wifi heavy traffic
2020-06-21 15:19:35.241 2600-3016/? D/BtGatt.CustomScanStrategy: MonitorThread wlan0
2020-06-21 15:19:35.241 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.241 2600-3016/? D/BtGatt.ScanManager: startWatchWIFITraffic
2020-06-21 15:19:35.241 2600-3016/? D/BtGatt.CustomScanStrategy: getCurrAction: 0
2020-06-21 15:19:35.249 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.249 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.249 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.250 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.252 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.252 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.252 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.252 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.261 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.261 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.261 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.261 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.262 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.263 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.263 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.263 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.263 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.263 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.264 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.264 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.264 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.265 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.265 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.265 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.970 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.971 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.971 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.971 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.971 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.972 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.972 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.972 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.972 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.973 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.976 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.976 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.979 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:35.997 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.998 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.998 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:35.999 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:35.999 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:35.999 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:35.999 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:36.000 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:36.004 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:36.182 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:36.182 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:36.183 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:36.183 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:36.183 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:36.184 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:36.184 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:36.185 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:36.192 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:36.786 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:36.787 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:36.787 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:36.788 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:36.788 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:36.789 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:36.789 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:36.789 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:36.798 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:37.280 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:37.281 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:37.281 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:37.281 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:37.282 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:37.282 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:37.283 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:37.283 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:37.289 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:37.327 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:37.328 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:37.328 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:37.328 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:37.648 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:37.648 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:37.649 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:37.650 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:37.832 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:37.834 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:37.834 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:37.834 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:37.834 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:37.834 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:37.835 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:37.835 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:37.835 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:37.835 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:37.835 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:37.836 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:37.840 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:37.954 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 15:19:38.145 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.146 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.146 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.147 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.147 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.148 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.148 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.148 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.154 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:38.383 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.385 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.385 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.386 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.386 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.388 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.388 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.388 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.389 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.390 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.390 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.390 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.399 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:38.564 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.565 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.566 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.566 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.922 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.922 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.922 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.923 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.929 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.929 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.930 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.930 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.931 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.932 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.932 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.932 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.933 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:38.933 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:38.933 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:38.933 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:38.939 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:39.226 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:39.228 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:39.229 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:39.230 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:39.230 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:39.231 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:39.231 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:39.232 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:39.232 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:39.232 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:39.233 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:39.233 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:39.242 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:39.293 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:39.294 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:39.294 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:39.294 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:39.294 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:39.295 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:39.295 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:39.296 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:39.302 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:40.009 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.010 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.010 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.012 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.012 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.013 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.013 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.014 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.019 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:40.026 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.027 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.028 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.028 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.028 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.028 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.029 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.029 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.033 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:40.038 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.038 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.038 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.038 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.038 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.039 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.039 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.040 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.044 2600-3291/? D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@a9680c6
2020-06-21 15:19:40.212 23449-23449/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: stopDeviceScan
2020-06-21 15:19:40.215 23449-23615/com.example.otter_feeder I/RxBle#CancellableSubscription: Scan operation is requested to stop.
2020-06-21 15:19:40.219 23449-23615/com.example.otter_feeder D/BluetoothAdapter: isLeEnabled(): ON
2020-06-21 15:19:40.221 2600-3016/? D/BtGatt.CustomScanStrategy: CustomScanStrategy stopWatchWIFITraffic
2020-06-21 15:19:40.222 2600-23810/? D/BtGatt.CustomScanStrategy: interupted
2020-06-21 15:19:40.222 2600-23810/? D/BtGatt.CustomScanStrategy: MonitorThread exit
2020-06-21 15:19:40.222 2600-3016/? D/BtGatt.ScanManager: stopWatchWIFITraffic
2020-06-21 15:19:40.224 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.225 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.225 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.226 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.230 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.230 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.230 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.230 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.231 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back-->
2020-06-21 15:19:40.232 2600-3024/? D/bt_hci: hciEventReceived-->
2020-06-21 15:19:40.232 2600-3024/? D/bt_hci: hciEventReceived<--
2020-06-21 15:19:40.232 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:19:40.939 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 15:19:40.939 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged

And here is the log when it doesn't return any device:

2020-06-21 15:25:42.399 639-3045/? D/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::event call back<--
2020-06-21 15:25:44.838 2638-2958/? I/LocationControllerImpl: refreshViews mAreActiveLocationRequests=false
2020-06-21 15:25:45.489 23449-23449/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: startDeviceScan
2020-06-21 15:25:46.008 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 15:25:47.012 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 15:25:47.012 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 15:25:50.010 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 15:25:50.495 23449-23449/com.example.otter_feeder D/com.polidea.flutter_ble_lib.FlutterBleLibPlugin: on native side observed method: stopDeviceScan
    
    --------- beginning of system
2020-06-21 15:25:51.580 1919-4464/? D/NetworkPolicy: uid 10073 is allowed on unmetered network
2020-06-21 15:25:54.013 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 15:25:58.014 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 15:25:59.813 2600-2600/? D/HeadsetPhoneState: Enter onSignalStrengthsChanged
2020-06-21 15:25:59.813 2600-2600/? D/HeadsetPhoneState: Exit onSignalStrengthsChanged
2020-06-21 15:26:02.012 2638-3311/? D/TrafficStatsHelper: transmitted_validWifiData.get(0) = wlan0
2020-06-21 15:26:03.174 1919-2447/? D/NetworkPolicy: uid 10138 is allowed on unmetered network
2020-06-21 15:26:03.176 1919-2447/? I/chatty: uid=1000(system) ConnectivityThr identical 12 lines
2020-06-21 15:26:03.176 1919-2447/? D/NetworkPolicy: uid 10138 is allowed on unmetered network
2020-06-21 15:26:03.176 1919-2447/? D/NetworkPolicy: uid 10140 is allowed on unmetered network

As far I can see, when no devices are returned, these lines are missing:

2020-06-21 15:19:35.208 23449-23449/com.example.otter_feeder D/RxBle#ClientOperationQueue: QUEUED   ScanOperationApi21(116670761)
2020-06-21 15:19:35.211 23449-23603/com.example.otter_feeder D/RxBle#ClientOperationQueue: STARTED  ScanOperationApi21(116670761)
2020-06-21 15:19:35.213 23449-23615/com.example.otter_feeder I/RxBle#QueueOperation: Scan operation is requested to start.

@mikolak
Copy link
Collaborator

mikolak commented Jun 21, 2020

It seems as if native client was not there. Are you using destroyClient() between the calls?

@fpabl0
Copy link
Author

fpabl0 commented Jun 21, 2020

No, I am using the Bloc pattern and the only place I use it is in a dispose method:

  void dispose() async {
    await stopScan();
    await _bleManager?.destroyClient();
    await _scanSubscription?.cancel();
    await _connStateSubscription?.cancel();
  }

Then this method is called here: (I am using Provider lib)

@override
  Widget build(BuildContext context) {
    return MultiProvider(
      providers: [
        Provider<FeederBloc>(
          create: (_) => new FeederBloc(),
          dispose: (_, bloc) => bloc.dispose(),
        ),
       ....

Also, I don't think that can be the problem, because it occur in a random way, for example, if I try to scan devices after it returns no devices, it could now return all the devices or maybe not.

@mikolak
Copy link
Collaborator

mikolak commented Jun 22, 2020

Try setting a breakpoint on destroyClient() or somewhere in FlutterBleLibPlugin class to check if the adapter is set. Since no operation is queued in your other log, you might either be calling when there's no adapter or the adapter's too busy, ie. you're changing radio state too fast.

@fpabl0
Copy link
Author

fpabl0 commented Jun 22, 2020

Hmm ok thanks, changing the radio state too fast, maybe explain why sometimes I don't get any results. However what about the other problem? Sometimes the function does not show all the available devices.

@mikolak
Copy link
Collaborator

mikolak commented Jun 22, 2020

Perhaps the advertisement simply didn't come? 5 seconds isn't a lot. Try adding a two second delay between stopping and restarting the scan and lengthen the scanning period to 15 seconds.

Can you add a log to your dispose method to see if it's not called when it shouldn't be?

@fpabl0
Copy link
Author

fpabl0 commented Jun 22, 2020

Thanks for the suggestion, I will take into account to add a delay between stopping and restarting the scan. On the other hand, I don't think 5 seconds isn't a lot. This application I am doing is a refactor of a previous application I did with Ionic framework, and in that case 5 seconds were enough to identify all the near devices.

I have debugged with a breakpoint on my dispose method, and it is never called, as it just have to be called at the end of the app.

@dariuszseweryn
Copy link
Collaborator

5 seconds may or may not be a lot. If you cannot scan all devices you expect you can change scan mode to more aggressive.
As for the second case where you get no results – are all scans made on the same instance of the manager? Or the managers are never disposed but new ones are being created with each app reload?

@fpabl0
Copy link
Author

fpabl0 commented Jun 22, 2020

Hi @dariuszseweryn, yes that's why I changed the default LowPower mode to Balanced mode, I just wonder why I can get all the devices in LowPower mode with the other app.
Scans are made on the same instance of the manager, the instance is created when the bloc is created, and it is created just once when the app starts, and then it is disposed when the app finishes.

@dariuszseweryn
Copy link
Collaborator

So I assume you do not try to start more than 5 scans in any 30 second window. I also assume you do not try to run the scan in the background. Am I correct?
As for the performance — I cannot really tell why you experience different results with different apps. I cannot find mode changes in the readme of the plugin that is apparently used by Ionic.

@fpabl0
Copy link
Author

fpabl0 commented Jun 22, 2020

Do you mean simultaneously? If so, then I am just one scan at time. If you do not mean simultaneously, then yes, it is possible to start more than five scans in a 30 second window, because I let the user to start or stop the scans but with a default timeout of 5 seconds (if they don't press the stop button).
In the case of Ionic, they don't have scan mode changes, because they are using deprecated android api, but according to the documentation ScanLowPowerMode is the the default one, so I assume that they used it, but honestly I am not sure.
Finally, don't get me wrong I'm not saying that Ionic plugin is better than this one, actually it isn't, that's why I migrated to flutter, your library is by far more performant than Ionic one (and even better than others in flutter), I just wanted to understand why these differences at the scanning time.

@dariuszseweryn
Copy link
Collaborator

In the case of Ionic, they don't have scan mode changes, because they are using deprecated android api, but according to the documentation ScanLowPowerMode is the the default one, so I assume that they used it, but honestly I am not sure.

Legacy API used aggressive scan mode.

Do you mean simultaneously? If so, then I am just one scan at time. If you do not mean simultaneously, then yes, it is possible to start more than five scans in a 30 second window, because I let the user to start or stop the scans but with a default timeout of 5 seconds (if they don't press the stop button).

Not necessarily simultaneously. Serial calls may trigger throttling as well. Thing is that the library should cover that situation if the manager is not being recreated in the mean time.

Do you have any specific recreation scenario under which the results are not returned? The more repeatable the better.

@fpabl0
Copy link
Author

fpabl0 commented Jun 23, 2020

Legacy API used aggressive scan mode.

Oh sorry, I didn't know it.

Do you have any specific recreation scenario under which the results are not returned? The more repeatable the better.

I have created a basic project based on the one I am developing in order to give you a way to test:
https://github.com/fpabl0/flutter_ble_test_tmp
You only have to press Scan button in an interval of 2 or 5 seconds (previously stopped) and probably you will get "Could not find near devices".

@dariuszseweryn
Copy link
Collaborator

dariuszseweryn commented Jun 24, 2020

Do you have any error handling there? I can't see it. I am not yet fluent with Flutter/Dart

@fpabl0
Copy link
Author

fpabl0 commented Jun 24, 2020

I'm just handling the error in _init() function, then I send it to state stream:

  // Init bluetooth
  Future<void> _init() async {
    try {
      _stateSink.add(DeviceBlocState.INITIALIZING);
      await _bleManager.createClient();
      await _bleManager.setLogLevel(LogLevel.verbose);
      await _checkPermissions();
      await _waitForBluetoothPoweredOn();
      _stateSink.add(DeviceBlocState.IDLE);
    } catch (e) {
      _stateSink.addError("Error initializing bluetooth: ${e.toString()}");
    }
  }

I'm not handling errors in startScan and stopScan functions, because startScan returns a stream, and an error in stopScan, at least for me, is not very important to the final user.

@dariuszseweryn
Copy link
Collaborator

From what I know the Stream may error out. I am not familiar with how it should be handled. I just see that it does not seem to be handled in the code you provided.

@fpabl0
Copy link
Author

fpabl0 commented Jun 24, 2020

You are right, it's my mistake. I have updated my repo handling stream errors.
In these two places.
1.

  // Wait Bluetooth on
  Future<void> _waitForBluetoothPoweredOn() async {
    Completer completer = Completer();
    StreamSubscription<BluetoothState> subscription;
    subscription = _bleManager.observeBluetoothState(emitCurrentValue: true).listen(
      (bluetoothState) async {
        if (bluetoothState == BluetoothState.POWERED_ON && !completer.isCompleted) {
          await subscription.cancel();
          completer.complete();
        }
      },
      // handling stream error
      onError: (error) {
        completer.completeError(error);
      },
      // automatically cancel the subscription on first error
      cancelOnError: true,
    );
    return completer.future;
  }
  // Start BLE devices scan
  void startScan() {
    if (lastState != DeviceBlocState.IDLE) return;
    _stateSink.add(DeviceBlocState.SCANNING);
    _devicesList.clear();
    _devicesSink.add(null);

    _scanSubscription = _bleManager
        .startPeripheralScan(scanMode: ScanMode.balanced, allowDuplicates: false)
        .listen(
      (device) {
        for (var d in _devicesList) {
          if (device.peripheral.identifier == d.peripheral.identifier) return;
        }
        _devicesList.add(device);
        _devicesSink.add(_devicesList.sublist(0));
      },
      // handling stream error
      onError: (error) async {
        _stateSink.addError(error);
        await stopScan(); // stop scan here?
      },
      // automatically cancel the subscription on first error
      cancelOnError: true,
    );

    _timeoutTimer = new Timer(_TIMEOUT_DURATION, () => stopScan());
  }

However, none of them are triggered so the error is not there, and the problem that sometimes does not return any result still appears.

@fati-chan
Copy link

Hi !
I don't know if this might help you but you can check it anyway ...
In my case, everything was working just fine but suddenly startPeripheralScan didn't return any results anymore and no errors were shown either ... after many tries I finally figured out that the location services on my Android device got disabled 😑
so turning on the location services on my phone solved the problem.

@dariuszseweryn
Copy link
Collaborator

Confirmed. The problem is that the native side is reporting an issue with scanning but the flutter side is not yet listening (race condition). Working on a fix.

@mikolak mikolak added the bug Something isn't working label Jul 3, 2020
@dariuszseweryn dariuszseweryn changed the title Sometimes startPeripheralScan doesn't return any result [Android] Sometimes startPeripheralScan doesn't return any result Jul 3, 2020
@dariuszseweryn dariuszseweryn changed the title [Android] Sometimes startPeripheralScan doesn't return any result Sometimes startPeripheralScan doesn't return any result Jul 3, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Android bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants