Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 30803361 authored by Vinay Kalia's avatar Vinay Kalia Committed by Ajay Panicker
Browse files

Improve BLE scan attribution to facilitate debugging power issues 

Following changes are made to improve BLE scan dumpsys:
1. All stats in AppScanStats assumed one scan per application.
   This is not true for many applications. Fix scanning stats
   to support multiple scans per application:
      a. Fix number of scans started/stopped counters.
      b. Fix scan min/max/avg/total time.
      c. Fix scan start/stop indication to batterystats.

2. Show ongoing scans as a separate list of scans.

Example:
   <app-name> (Registered)
   LE scans (started/stopped)         : 13 / 11
   Scan time in ms (min/max/avg/total): 1098 / 227509 / 19805 / 257469
   Total number of results            : 2623
   Last 5 scans                       :
     2017/06/26 14:55:02 - 6659ms 59 results (7)
     2017/06/26 14:55:13 - 1113ms 6 results (8)
     2017/06/26 14:55:14 - 10012ms Filter 0 results (8)
     2017/06/26 14:55:24 - 1106ms 7 results (8)
     2017/06/26 14:57:56 - 10007ms 100 results (9)
   Ongoing scans:
     2017/06/26 14:55:09 - 227509ms 2232 results (7)
     2017/06/26 14:58:06 - 50463ms Filter 0 results (9)

   Application ID                     : 5
   UUID                               : xxxx

BUG: 62389939
Test: Tested a few BLE scanning applications which included misbehaving
applications.

Change-Id: Iaade4ce4bf06533415b49bc3635866b1bf0db937
parent 1059250b

android/app/src/com/android/bluetooth/gatt/AppScanStats.java

+98 −66
Original line number Diff line number Diff line
@@ -28,6 +28,7 @@ import java.util.ArrayList; 
import java.util.Date;

import java.util.Iterator;

import java.util.List;

import java.util.HashMap;



import com.android.bluetooth.btservice.BluetoothProto;

/**
@@ -55,15 +56,17 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        boolean background;

        boolean filtered;

        int results;

        int scannerId;



        public LastScan(long timestamp, long duration, boolean opportunistic, boolean background,

                boolean filtered) {

                boolean filtered, int scannerId) {

            this.duration = duration;

            this.timestamp = timestamp;

            this.opportunistic = opportunistic;

            this.background = background;

            this.filtered = filtered;

            this.results = 0;

            this.scannerId = scannerId;

        }

    }
@@ -82,12 +85,13 @@ import com.android.bluetooth.btservice.BluetoothProto; 
    WorkSource workSource; // Used for BatteryStats

    int scansStarted = 0;

    int scansStopped = 0;

    boolean isScanning = false;

    boolean isRegistered = false;

    long minScanTime = Long.MAX_VALUE;

    long maxScanTime = 0;

    long totalScanTime = 0;

    List<LastScan> lastScans = new ArrayList<LastScan>(NUM_SCAN_DURATIONS_KEPT + 1);

    long mScanStartTime = 0;

    long mTotalScanTime = 0;

    List<LastScan> lastScans = new ArrayList<LastScan>(NUM_SCAN_DURATIONS_KEPT);

    HashMap<Integer, LastScan> ongoingScans = new HashMap<Integer, LastScan>();

    long startTime = 0;

    long stopTime = 0;

    int results = 0;
@@ -105,9 +109,10 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        workSource = source;

    }



    synchronized void addResult() {

        if (!lastScans.isEmpty()) {

            int batteryStatsResults = ++lastScans.get(lastScans.size() - 1).results;

    synchronized void addResult(int scannerId) {

        LastScan scan = getScanFromScannerId(scannerId);

        if (scan != null) {

            int batteryStatsResults = ++scan.results;



            // Only update battery stats after receiving 100 new results in order

            // to lower the cost of the binder transaction
@@ -123,20 +128,27 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        results++;

    }



    synchronized void recordScanStart(ScanSettings settings, boolean filtered) {

        if (isScanning)

            return;

    boolean isScanning() {

        return !ongoingScans.isEmpty();

    }



    LastScan getScanFromScannerId(int scannerId) {

        return ongoingScans.get(scannerId);

    }



    synchronized void recordScanStart(ScanSettings settings, boolean filtered, int scannerId) {

        LastScan existingScan = getScanFromScannerId(scannerId);

        if (existingScan != null) {

            return;

        }

        this.scansStarted++;

        isScanning = true;

        startTime = SystemClock.elapsedRealtime();



        LastScan scan = new LastScan(startTime, 0, false, false, filtered);

        LastScan scan = new LastScan(startTime, 0, false, false, filtered, scannerId);

        if (settings != null) {

          scan.opportunistic = settings.getScanMode() == ScanSettings.SCAN_MODE_OPPORTUNISTIC;

          scan.background = (settings.getCallbackType() & ScanSettings.CALLBACK_TYPE_FIRST_MATCH) != 0;

        }

        lastScans.add(scan);



        BluetoothProto.ScanEvent scanEvent = new BluetoothProto.ScanEvent();

        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_START);
@@ -145,33 +157,33 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        scanEvent.setInitiator(truncateAppName(appName));

        gattService.addScanEvent(scanEvent);



        if (!isScanning()) {

            try {

                boolean isUnoptimized = !(scan.filtered || scan.background || scan.opportunistic);

                mScanStartTime = startTime;

                batteryStats.noteBleScanStarted(workSource, isUnoptimized);

            } catch (RemoteException e) {

                /* ignore */

            }

        }



    synchronized void recordScanStop() {

        if (!isScanning)

          return;

        ongoingScans.put(scannerId, scan);

    }



    synchronized void recordScanStop(int scannerId) {

        LastScan scan = getScanFromScannerId(scannerId);

        if (scan == null) {

            return;

        }

        this.scansStopped++;

        isScanning = false;

        stopTime = SystemClock.elapsedRealtime();

        long scanDuration = stopTime - startTime;



        minScanTime = Math.min(scanDuration, minScanTime);

        maxScanTime = Math.max(scanDuration, maxScanTime);

        totalScanTime += scanDuration;



        LastScan curr = lastScans.get(lastScans.size() - 1);

        curr.duration = scanDuration;



        if (lastScans.size() > NUM_SCAN_DURATIONS_KEPT) {

        long scanDuration = stopTime - scan.timestamp;

        scan.duration = scanDuration;

        ongoingScans.remove(scannerId);

        if (lastScans.size() >= NUM_SCAN_DURATIONS_KEPT) {

            lastScans.remove(0);

        }

        lastScans.add(scan);



        BluetoothProto.ScanEvent scanEvent = new BluetoothProto.ScanEvent();

        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_STOP);
@@ -180,23 +192,28 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        scanEvent.setInitiator(truncateAppName(appName));

        gattService.addScanEvent(scanEvent);



        if (!isScanning()) {

            try {

                long totalDuration = stopTime - mScanStartTime;

                mTotalScanTime += totalDuration;

                minScanTime = Math.min(totalDuration, minScanTime);

                maxScanTime = Math.max(totalDuration, maxScanTime);

                // Inform battery stats of any results it might be missing on

                // scan stop

            batteryStats.noteBleScanResults(workSource, curr.results % 100);

                batteryStats.noteBleScanResults(workSource, scan.results % 100);

                batteryStats.noteBleScanStopped(workSource);

            } catch (RemoteException e) {

                /* ignore */

            }

        }

    }



    synchronized void setScanTimeout() {

        if (!isScanning)

          return;

    synchronized void setScanTimeout(int scannerId) {

        if (!isScanning()) return;



        if (!lastScans.isEmpty()) {

            LastScan curr = lastScans.get(lastScans.size() - 1);

            curr.timeout = true;

        LastScan scan = getScanFromScannerId(scannerId);

        if (scan != null) {

            scan.timeout = true;

        }

    }
@@ -210,11 +227,10 @@ import com.android.bluetooth.btservice.BluetoothProto; 
    }



    synchronized boolean isScanningTooLong() {

        if (lastScans.isEmpty() || !isScanning) {

        if (!isScanning()) {

            return false;

        }



        return (SystemClock.elapsedRealtime() - startTime) > SCAN_TIMEOUT_MS;

        return (SystemClock.elapsedRealtime() - mScanStartTime) > SCAN_TIMEOUT_MS;

    }



    // This function truncates the app name for privacy reasons. Apps with
@@ -243,19 +259,24 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        long minScan = minScanTime;

        long scanDuration = 0;



        if (isScanning) {

            scanDuration = currTime - startTime;

        if (isScanning()) {

            scanDuration = currTime - mScanStartTime;

        }

        minScan = Math.min(scanDuration, minScan);

        maxScan = Math.max(scanDuration, maxScan);

        }



        if (minScan == Long.MAX_VALUE) {

            minScan = 0;

        }



        /*TODO: Average scan time can be skewed for

         * multiple scan clients. It will show less than

         * actual value.

         * */

        long avgScan = 0;

        long totalScanTime = mTotalScanTime + scanDuration;

        if (scansStarted > 0) {

            avgScan = (totalScanTime + scanDuration) / scansStarted;

            avgScan = totalScanTime / scansStarted;

        }



        sb.append("  " + appName);
@@ -281,16 +302,14 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        sb.append("  Total number of results            : " +

                  results + "\n");



        long currentTime = System.currentTimeMillis();

        long elapsedRt = SystemClock.elapsedRealtime();

        if (!lastScans.isEmpty()) {

            int lastScansSize = scansStopped < NUM_SCAN_DURATIONS_KEPT ?

                                scansStopped : NUM_SCAN_DURATIONS_KEPT;

            sb.append("  Last " + lastScansSize +

                      " scans                       :\n");

            sb.append("  Last " + lastScans.size() + " scans                       :\n");



            for (int i = 0; i < lastScansSize; i++) {

            for (int i = 0; i < lastScans.size(); i++) {

                LastScan scan = lastScans.get(i);

                Date timestamp = new Date(System.currentTimeMillis() - SystemClock.elapsedRealtime()

                        + scan.timestamp);

                Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);

                sb.append("    " + dateFormat.format(timestamp) + " - ");

                sb.append(scan.duration + "ms ");

                if (scan.opportunistic) sb.append("Opp ");
@@ -298,6 +317,24 @@ import com.android.bluetooth.btservice.BluetoothProto; 
                if (scan.timeout) sb.append("Forced ");

                if (scan.filtered) sb.append("Filter ");

                sb.append(scan.results + " results");

                sb.append(" (" + scan.scannerId + ")");

                sb.append("\n");

            }

        }



        if (!ongoingScans.isEmpty()) {

            sb.append("  Ongoing scans                      :\n");

            for (Integer key : ongoingScans.keySet()) {

                LastScan scan = ongoingScans.get(key);

                Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);

                sb.append("    " + dateFormat.format(timestamp) + " - ");

                sb.append((elapsedRt - scan.timestamp) + "ms ");

                if (scan.opportunistic) sb.append("Opp ");

                if (scan.background) sb.append("Back ");

                if (scan.timeout) sb.append("Forced ");

                if (scan.filtered) sb.append("Filter ");

                sb.append(scan.results + " results");

                sb.append(" (" + scan.scannerId + ")");

                sb.append("\n");

            }

        }
@@ -309,11 +346,6 @@ import com.android.bluetooth.btservice.BluetoothProto; 
            sb.append("  UUID                               : " +

                      appEntry.uuid + "\n");



            if (isScanning) {

                sb.append("  Current scan duration in ms        : " +

                          scanDuration + "\n");

            }



            List<ContextMap.Connection> connections =

              contextMap.getConnectionByApp(appEntry.id);

android/app/src/com/android/bluetooth/gatt/GattService.java

+4 −4
Original line number Diff line number Diff line
@@ -781,7 +781,7 @@ public class GattService extends ProfileService { 
            }



            try {

                app.appScanStats.addResult();

                app.appScanStats.addResult(client.scannerId);

                if (app.callback != null) {

                    app.callback.onScanResult(result);

                } else {
@@ -1596,7 +1596,7 @@ public class GattService extends ProfileService { 
            scanClient.stats = app;



            boolean isFilteredScan = (filters != null) && !filters.isEmpty();

            app.recordScanStart(settings, isFilteredScan);

            app.recordScanStart(settings, isFilteredScan, scannerId);

        }



        mScanManager.startScan(scanClient);
@@ -1644,7 +1644,7 @@ public class GattService extends ProfileService { 
            scanClient.stats = app;



            boolean isFilteredScan = (piInfo.filters != null) && !piInfo.filters.isEmpty();

            app.recordScanStart(piInfo.settings, isFilteredScan);

            app.recordScanStart(piInfo.settings, isFilteredScan, scannerId);

        }



        mScanManager.startScan(scanClient);
@@ -1663,7 +1663,7 @@ public class GattService extends ProfileService { 


        AppScanStats app = null;

        app = mScannerMap.getAppScanStatsById(client.scannerId);

        if (app != null) app.recordScanStop();

        if (app != null) app.recordScanStop(client.scannerId);



        mScanManager.stopScan(client);

    }

android/app/src/com/android/bluetooth/gatt/ScanManager.java

+1 −1
Original line number Diff line number Diff line
@@ -686,7 +686,7 @@ public class ScanManager { 
                        "Moving scan client to opportunistic (scannerId " + client.scannerId + ")");

                setOpportunisticScanClient(client);

                removeScanFilters(client.scannerId);

                client.stats.setScanTimeout();

                client.stats.setScanTimeout(client.scannerId);

            }



            // The scan should continue for background scans