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

Commit bcdae28f authored by Vinay Kalia's avatar Vinay Kalia
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 eaebb031

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

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

import java.util.Date;

import java.util.Iterator;

import java.util.Iterator;

import java.util.List;

import java.util.List;

import java.util.HashMap;





import com.android.bluetooth.btservice.BluetoothProto;

import com.android.bluetooth.btservice.BluetoothProto;

/**

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

        boolean background;

        boolean filtered;

        boolean filtered;

        int results;

        int results;

        int scannerId;





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

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

                boolean filtered) {

                boolean filtered, int scannerId) {

            this.duration = duration;

            this.duration = duration;

            this.timestamp = timestamp;

            this.timestamp = timestamp;

            this.opportunistic = opportunistic;

            this.opportunistic = opportunistic;

            this.background = background;

            this.background = background;

            this.filtered = filtered;

            this.filtered = filtered;

            this.results = 0;

            this.results = 0;

            this.scannerId = scannerId;

        }

        }

    }

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

    WorkSource workSource; // Used for BatteryStats

    int scansStarted = 0;

    int scansStarted = 0;

    int scansStopped = 0;

    int scansStopped = 0;

    boolean isScanning = false;

    boolean isRegistered = false;

    boolean isRegistered = false;

    long minScanTime = Long.MAX_VALUE;

    long minScanTime = Long.MAX_VALUE;

    long maxScanTime = 0;

    long maxScanTime = 0;

    long totalScanTime = 0;

    long mScanStartTime = 0;

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

    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 startTime = 0;

    long stopTime = 0;

    long stopTime = 0;

    int results = 0;

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

        workSource = source;

    }

    }





    synchronized void addResult() {

    synchronized void addResult(int scannerId) {

        if (!lastScans.isEmpty())

        LastScan scan = getScanFromScannerId(scannerId);

            lastScans.get(lastScans.size() - 1).results++;

        if (scan != null) {

            scan.results++;

        }





        results++;

        results++;

    }

    }





    synchronized void recordScanStart(ScanSettings settings, boolean filtered) {

    boolean isScanning() {

        if (isScanning)

        return !ongoingScans.isEmpty();

            return;

    }



    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++;

        this.scansStarted++;

        isScanning = true;

        startTime = SystemClock.elapsedRealtime();

        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) {

        if (settings != null) {

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

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

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

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

        }

        }

        lastScans.add(scan);





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

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

        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_START);

        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_START);
@@ -134,32 +147,32 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        scanEvent.setInitiator(truncateAppName(appName));

        scanEvent.setInitiator(truncateAppName(appName));

        gattService.addScanEvent(scanEvent);

        gattService.addScanEvent(scanEvent);





        if (!isScanning()) {

            try {

            try {

                mScanStartTime = startTime;

                batteryStats.noteBleScanStarted(workSource);

                batteryStats.noteBleScanStarted(workSource);

            } catch (RemoteException e) {

            } catch (RemoteException e) {

                /* ignore */

                /* ignore */

            }

            }

        }

        }





    synchronized void recordScanStop() {

        ongoingScans.put(scannerId, scan);

        if (!isScanning)

    }

          return;





    synchronized void recordScanStop(int scannerId) {

        LastScan scan = getScanFromScannerId(scannerId);

        if (scan == null) {

            return;

        }

        this.scansStopped++;

        this.scansStopped++;

        isScanning = false;

        stopTime = SystemClock.elapsedRealtime();

        stopTime = SystemClock.elapsedRealtime();

        long scanDuration = stopTime - startTime;

        long scanDuration = stopTime - scan.timestamp;



        scan.duration = scanDuration;

        minScanTime = Math.min(scanDuration, minScanTime);

        ongoingScans.remove(scannerId);

        maxScanTime = Math.max(scanDuration, maxScanTime);

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

        totalScanTime += scanDuration;



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

        curr.duration = scanDuration;



        if (lastScans.size() > NUM_SCAN_DURATIONS_KEPT) {

            lastScans.remove(0);

            lastScans.remove(0);

        }

        }

        lastScans.add(scan);





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

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

        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_STOP);

        scanEvent.setScanEventType(BluetoothProto.ScanEvent.SCAN_EVENT_STOP);
@@ -168,20 +181,25 @@ import com.android.bluetooth.btservice.BluetoothProto; 
        scanEvent.setInitiator(truncateAppName(appName));

        scanEvent.setInitiator(truncateAppName(appName));

        gattService.addScanEvent(scanEvent);

        gattService.addScanEvent(scanEvent);





        if (!isScanning()) {

            try {

            try {

                long totalDuration = stopTime - mScanStartTime;

                mTotalScanTime += totalDuration;

                minScanTime = Math.min(totalDuration, minScanTime);

                maxScanTime = Math.max(totalDuration, maxScanTime);

                batteryStats.noteBleScanStopped(workSource);

                batteryStats.noteBleScanStopped(workSource);

            } catch (RemoteException e) {

            } catch (RemoteException e) {

                /* ignore */

                /* ignore */

            }

            }

        }

        }

    }





    synchronized void setScanTimeout() {

    synchronized void setScanTimeout(int scannerId) {

        if (!isScanning)

        if (!isScanning()) return;

          return;





        if (!lastScans.isEmpty()) {

        LastScan scan = getScanFromScannerId(scannerId);

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

        if (scan != null) {

            curr.timeout = true;

            scan.timeout = true;

        }

        }

    }

    }
@@ -195,11 +213,10 @@ import com.android.bluetooth.btservice.BluetoothProto; 
    }

    }





    synchronized boolean isScanningTooLong() {

    synchronized boolean isScanningTooLong() {

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

        if (!isScanning()) {

            return false;

            return false;

        }

        }



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

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

    }

    }





    // This function truncates the app name for privacy reasons. Apps with

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

        long minScan = minScanTime;

        long scanDuration = 0;

        long scanDuration = 0;





        if (isScanning) {

        if (isScanning()) {

            scanDuration = currTime - startTime;

            scanDuration = currTime - mScanStartTime;

        }

        minScan = Math.min(scanDuration, minScan);

        minScan = Math.min(scanDuration, minScan);

        maxScan = Math.max(scanDuration, maxScan);

        maxScan = Math.max(scanDuration, maxScan);

        }





        if (minScan == Long.MAX_VALUE) {

        if (minScan == Long.MAX_VALUE) {

            minScan = 0;

            minScan = 0;

        }

        }





        long avgScan = 0;

        long avgScan = 0;

        long totalScanTime = mTotalScanTime + scanDuration;

        if (scansStarted > 0) {

        if (scansStarted > 0) {

            avgScan = (totalScanTime + scanDuration) / scansStarted;

            avgScan = totalScanTime / scansStarted;

        }

        }





        sb.append("  " + appName);

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

        sb.append("  Total number of results            : " +

                  results + "\n");

                  results + "\n");





        long currentTime = System.currentTimeMillis();

        long elapsedRt = SystemClock.elapsedRealtime();

        if (!lastScans.isEmpty()) {

        if (!lastScans.isEmpty()) {

            int lastScansSize = scansStopped < NUM_SCAN_DURATIONS_KEPT ?

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

                                scansStopped : NUM_SCAN_DURATIONS_KEPT;

            sb.append("  Last " + lastScansSize +

                      " scans                       :\n");





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

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

                LastScan scan = lastScans.get(i);

                LastScan scan = lastScans.get(i);

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

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

                        + scan.timestamp);

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

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

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

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

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

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

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

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

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

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

                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");

                sb.append("\n");

            }

            }

        }

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

            sb.append("  UUID                               : " +

                      appEntry.uuid + "\n");

                      appEntry.uuid + "\n");





            if (isScanning) {

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

                          scanDuration + "\n");

            }



            List<ContextMap.Connection> connections =

            List<ContextMap.Connection> connections =

              contextMap.getConnectionByApp(appEntry.id);

              contextMap.getConnectionByApp(appEntry.id);

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

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

            }





            try {

            try {

                app.appScanStats.addResult();

                app.appScanStats.addResult(client.scannerId);

                app.callback.onScanResult(result);

                app.callback.onScanResult(result);

            } catch (RemoteException e) {

            } catch (RemoteException e) {

                Log.e(TAG, "Exception: " + e);

                Log.e(TAG, "Exception: " + e);
@@ -1483,7 +1483,7 @@ public class GattService extends ProfileService { 
            scanClient.stats = app;

            scanClient.stats = app;





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

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

            app.recordScanStart(settings, isFilteredScan);

            app.recordScanStart(settings, isFilteredScan, scannerId);

        }

        }





        mScanManager.startScan(scanClient);

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




        AppScanStats app = null;

        AppScanStats app = null;

        app = mScannerMap.getAppScanStatsById(client.scannerId);

        app = mScannerMap.getAppScanStatsById(client.scannerId);

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

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





        mScanManager.stopScan(client);

        mScanManager.stopScan(client);

    }

    }

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

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

                        "Moving scan client to opportunistic (scannerId " + client.scannerId + ")");

                setOpportunisticScanClient(client);

                setOpportunisticScanClient(client);

                removeScanFilters(client.scannerId);

                removeScanFilters(client.scannerId);

                client.stats.setScanTimeout();

                client.stats.setScanTimeout(client.scannerId);

            }

            }





            // The scan should continue for background scans

            // The scan should continue for background scans