AltBeacon / android-beacon-library

Allows Android apps to interact with BLE beacons
Apache License 2.0
2.84k stars 836 forks source link

org.altbeacon.beacon.service.ScanJob instance leaking #1060

Open alvindizon opened 2 years ago

alvindizon commented 2 years ago

Expected behavior

Library should ideally not have leaks.

Actual behavior

Leakcanary reports ScanJob is leaking.

Steps to reproduce this behavior

  1. Run app with leakcanary
  2. App should start detecting beacons provided there is one advertising
  3. Send app to background by pressing home

    Mobile device model and OS version

    Samsung A10, Android 11

    Android Beacon Library version

    2.19.3 IMPORTANT: This forum is reserved for feature requests or reproducible bugs with the library itself. If you need help with using the library with your project, please open a new question on StackOverflow.com.

Here are the logs I've seen:

2021-10-14 15:19:54.123 9660-9660/com.someapp.app I/ScanJob: onStopJob called for immediate scan org.altbeacon.beacon.service.ScanJob@826b93c
2021-10-14 15:19:54.123 9660-9660/com.someapp.app I/ScanJob: ScanJob Lifecycle STOP: org.altbeacon.beacon.service.ScanJob@826b93c
2021-10-14 15:19:54.220 9660-9660/com.someapp.app I/ScanJob: We are inside a beacon region.  We will not scan between cycles.
2021-10-14 15:19:54.240 9660-9660/com.someapp.app E/ScanHelper: Can't stop beacon parsing thread.
2021-10-14 15:19:54.385 9660-9660/com.someapp.app D/LeakCanary: Watching instance of org.altbeacon.beacon.service.ScanJob (org.altbeacon.beacon.service.ScanJob received Service#onDestroy() callback) with key ccc76655-888b-49d3-b5d1-9c936c7312af
2021-10-14 15:19:55.413 9660-9660/com.someapp.app I/BeaconManager: Cancelling scheduled jobs after unbind of last consumer.
2021-10-14 15:20:51.713 9660-12787/com.someapp.app D/LeakCanary: ​
    ====================================
    HEAP ANALYSIS RESULT
    ====================================
    1 APPLICATION LEAKS

    References underlined with "~~~" are likely causes.
    Learn more at https://squ.re/leaks.

    2105 bytes retained by leaking objects
    Signature: 7099d76a19d517f9c02f2a3824cee19b86c08331
    ┬───
    │ GC Root: Global variable in native code
    │
    ├─ android.bluetooth.le.BluetoothLeScanner$BleScanCallbackWrapper instance
    │    Leaking: UNKNOWN
    │    Retaining 3.9 kB in 44 objects
    │    ↓ BluetoothLeScanner$BleScanCallbackWrapper.mScanCallback
    │                                                ~~~~~~~~~~~~~
    ├─ org.altbeacon.beacon.service.scanner.CycledLeScannerForLollipop$4 instance
    │    Leaking: UNKNOWN
    │    Retaining 2.1 kB in 37 objects
    │    Anonymous subclass of android.bluetooth.le.ScanCallback
    │    ↓ CycledLeScannerForLollipop$4.this$0
    │                                   ~~~~~~
    ├─ org.altbeacon.beacon.service.scanner.CycledLeScannerForAndroidO instance
    │    Leaking: UNKNOWN
    │    Retaining 2.1 kB in 36 objects
    │    mContext instance of org.altbeacon.beacon.service.ScanJob
    │    ↓ CycledLeScanner.mContext
    │                      ~~~~~~~~
    ╰→ org.altbeacon.beacon.service.ScanJob instance
    ​     Leaking: YES (ObjectWatcher was watching this because org.altbeacon.beacon.service.ScanJob received
    ​     Service#onDestroy() callback and Service not held by ActivityThread)
    ​     Retaining 2.1 kB in 27 objects
    ​     key = ccc76655-888b-49d3-b5d1-9c936c7312af
    ​     watchDurationMillis = 6507
    ​     retainedDurationMillis = 1503
    ​     mApplication instance of com.someapp.app
    ​     mBase instance of android.app.ContextImpl
davidgyoung commented 2 years ago

Hi, @alvinsizon. Thanks for the analysis. It is unclear to me if the leakcanary report shows a real issue. The Callback objects it identifies are registered with the Android OS Bluetooth scanning APIs. The OS will hold a reference to these objects and will eventually release them. In theory this will happen when the scan stops, but there may be delays caused by the internal OS implementation that make these appear as leaks under analysis. Hopefully after some delay the references will be dropped and the objects will be garbage collected.

If you want to look into this further, I would suggest running the tool for a longer period after the ScanJob stops to give the OS time to release the callbacks. If you find it is still holding them five minutes later, you might confirm that the scan stop call is actually made, and see what class is holding the reference to the callback object after the 5 minutes.

alvindizon commented 2 years ago

Thanks @davidgyoung , I'm going to give your suggestion a go.

alvindizon commented 2 years ago

Hi @davidgyoung, I tried to keep LeakCanary running for 10 minutes (by setting watchDurationMillis to 600000), here's what I got:

2021-10-28 11:19:10.050 5499-5499/com.someapp.app I/ScanJob: onStopJob called for immediate scan org.altbeacon.beacon.service.ScanJob@3942045
2021-10-28 11:19:10.050 5499-5499/com.someapp.app I/ScanJob: ScanJob Lifecycle STOP: org.altbeacon.beacon.service.ScanJob@3942045
2021-10-28 11:19:10.134 5499-5499/com.someapp.app I/ScanJob: We are inside a beacon region.  We will not scan between cycles.
2021-10-28 11:19:10.534 5499-5499/com.someapp.app D/LeakCanary: Watching instance of org.altbeacon.beacon.service.ScanJob (org.altbeacon.beacon.service.ScanJob received Service#onDestroy() callback) with key de6d18f1-b319-4a57-8732-bb355bb0f71f
2021-10-28 11:19:10.710 5499-5499/com.someapp.app I/ScanJob: Using immediateScanJobId from manifest: 208352939
2021-10-28 11:19:10.714 5499-5499/com.someapp.app I/ScanJob: Using periodicScanJobId from manifest: 208352940
2021-10-28 11:19:10.913 5499-5499/com.someapp.app I/ScanJob: Using immediateScanJobId from manifest: 208352939
2021-10-28 11:19:10.918 5499-5499/com.someapp.app I/ScanJob: Using periodicScanJobId from manifest: 208352940
2021-10-28 11:19:11.007 5499-5499/com.someapp.app I/ScanJob: Using immediateScanJobId from manifest: 208352939
2021-10-28 11:19:11.011 5499-5499/com.someapp.app I/ScanJob: Using periodicScanJobId from manifest: 208352940
2021-10-28 11:30:04.708 5499-7598/com.someapp.app D/LeakCanary: ​
    ====================================
    HEAP ANALYSIS RESULT
    ====================================
    1 APPLICATION LEAKS

    References underlined with "~~~" are likely causes.
    Learn more at https://squ.re/leaks.

    5314 bytes retained by leaking objects
    Displaying only 1 leak trace out of 2 with the same signature
    Signature: 7099d76a19d517f9c02f2a3824cee19b86c08331
    ┬───
    │ GC Root: Global variable in native code
    │
    ├─ android.bluetooth.le.BluetoothLeScanner$BleScanCallbackWrapper instance
    │    Leaking: UNKNOWN
    │    Retaining 1.9 kB in 42 objects
    │    ↓ BluetoothLeScanner$BleScanCallbackWrapper.mScanCallback
    │                                                ~~~~~~~~~~~~~
    ├─ org.altbeacon.beacon.service.scanner.CycledLeScannerForLollipop$4 instance
    │    Leaking: UNKNOWN
    │    Retaining 1.1 kB in 36 objects
    │    Anonymous subclass of android.bluetooth.le.ScanCallback
    │    ↓ CycledLeScannerForLollipop$4.this$0
    │                                   ~~~~~~
    ├─ org.altbeacon.beacon.service.scanner.CycledLeScannerForAndroidO instance
    │    Leaking: UNKNOWN
    │    Retaining 1.1 kB in 35 objects
    │    mContext instance of org.altbeacon.beacon.service.ScanJob
    │    ↓ CycledLeScanner.mContext
    │                      ~~~~~~~~
    ╰→ org.altbeacon.beacon.service.ScanJob instance
    ​     Leaking: YES (ObjectWatcher was watching this because org.altbeacon.beacon.service.ScanJob received
    ​     Service#onDestroy() callback and Service not held by ActivityThread)
    ​     Retaining 2.7 kB in 29 objects
    ​     key = de6d18f1-b319-4a57-8732-bb355bb0f71f
    ​     watchDurationMillis = 600100
    ​     retainedDurationMillis = 595099
    ​     mApplication instance of com.someapp.app
    ​     mBase instance of android.app.ContextImpl
    ====================================

I'm not sure what's happening--it seems ScanJob is still running after 10 mins, but I might be misunderstanding this.

davidgyoung commented 2 years ago

@alvindizon thank you for looking into this.

when the ScanJob stops, it will stop all scanning with this call here:

https://github.com/AltBeacon/android-beacon-library/blob/master/lib/src/main/java/org/altbeacon/beacon/service/ScanJob.java#L226

this ends up calling:

https://github.com/AltBeacon/android-beacon-library/blob/master/lib/src/main/java/org/altbeacon/beacon/service/ScanJob.java#L243

which calls this destroy() method to clean up:

https://github.com/AltBeacon/android-beacon-library/blob/master/lib/src/main/java/org/altbeacon/beacon/service/scanner/CycledLeScanner.java#L262

We could try adding code to the destroy() method above to clear out the references to any objects that might be causing the leaks including mContext on CycledLeScanner, and leScanCallback onCycledLeScannerForAndroidLandCycledLeScannerForJellyBeanMr2`.

Also, you can increase logging with: beaconManager.serDebug(true) so it will show you more of what is going on.