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

Commit 9fa95f7c authored by Ajay Panicker's avatar Ajay Panicker
Browse files

Add extra logging for BLE scans

Added logging for application name, number of scans, and scan times
for each application that uses gatt scanning.

Example output:
GATT Client Map
  Entries: 1

  Application Name: com.broadcom.app.leexplorer (Registered)
  LE scans (started/stopped)       : 4 / 4
  Scan time in ms (min/max/avg)    : 6 / 7321 / 2744
  Time since last scan ended in ms : 3522
  Last 4 scans in ms (oldest first): 763 6 7321 2887
  Application ID                   : 5
  UUID                             : f69badb3-212b-40b5-b5b3-3bf9214310f9
  Connections: 1
    5: 6B:1F:6C:45:3D:DC

Bug: 26463429
Change-Id: I52376541a5b5874d0e40978990149a1283fd9c6a
parent 28ca6b2d
Loading
Loading
Loading
Loading
+178 −26
Original line number Diff line number Diff line
@@ -15,6 +15,8 @@
 */
package com.android.bluetooth.gatt;

import android.content.Context;
import android.os.Binder;
import android.os.IBinder;
import android.os.IBinder.DeathRecipient;
import android.os.IInterface;
@@ -23,6 +25,7 @@ import android.util.Log;
import java.util.ArrayList;
import java.util.HashSet;
import java.util.Iterator;
import java.util.LinkedList;
import java.util.List;
import java.util.NoSuchElementException;
import java.util.Set;
@@ -38,6 +41,46 @@ import java.util.Map;
/*package*/ class ContextMap<T> {
    private static final String TAG = GattServiceConfig.TAG_PREFIX + "ContextMap";

    /**
     * ScanStats class helps keep track of information about scans
     * on a per application basis.
     */
    class ScanStats {
        static final int NUM_SCAN_DURATIONS_KEPT = 5;

        int scansStarted = 0;
        int scansStopped = 0;
        boolean isScanning = false;
        boolean isRegistered = false;
        long minScanTime = Long.MAX_VALUE;
        long maxScanTime = 0;
        long totalScanTime = 0;
        List<Long> lastScans = new ArrayList<Long>(NUM_SCAN_DURATIONS_KEPT + 1);
        long startTime = 0;
        long stopTime = 0;

        void startScan() {
            this.scansStarted++;
            isScanning = true;
            startTime = System.currentTimeMillis();
        }

        void stopScan() {
            this.scansStopped++;
            isScanning = false;
            stopTime = System.currentTimeMillis();
            long currTime = stopTime - startTime;

            minScanTime = Math.min(currTime, minScanTime);
            maxScanTime = Math.max(currTime, maxScanTime);
            totalScanTime += currTime;
            lastScans.add(currTime);
            if (lastScans.size() > NUM_SCAN_DURATIONS_KEPT) {
                lastScans.remove(0);
            }
        }
    }

    /**
     * Connection class helps map connection IDs to device addresses.
     */
@@ -63,6 +106,9 @@ import java.util.Map;
        /** The id of the application */
        int id;

        /** The package name of the application */
        String name;

        /** Application callbacks */
        T callback;

@@ -78,9 +124,10 @@ import java.util.Map;
        /**
         * Creates a new app context.
         */
        App(UUID uuid, T callback) {
        App(UUID uuid, T callback, String name) {
            this.uuid = uuid;
            this.callback = callback;
            this.name = name;
        }

        /**
@@ -123,15 +170,30 @@ import java.util.Map;
    /** Our internal application list */
    List<App> mApps = new ArrayList<App>();

    /** Internal map to keep track of logging information by app name */
    HashMap<String, ScanStats> mScanStats = new HashMap<String, ScanStats>();

    /** Internal list of connected devices **/
    Set<Connection> mConnections = new HashSet<Connection>();

    /**
     * Add an entry to the application context list.
     */
    void add(UUID uuid, T callback) {
    void add(UUID uuid, T callback, Context context) {
        String appName = context.getPackageManager().getNameForUid(
                             Binder.getCallingUid());
        if (appName == null) {
            // Assign an app name if one isn't found
            appName = "Unknown App (UID: " + Binder.getCallingUid() + ")";
        }
        synchronized (mApps) {
            mApps.add(new App(uuid, callback));
            mApps.add(new App(uuid, callback, appName));
            ScanStats scanStats = mScanStats.get(appName);
            if (scanStats == null) {
                scanStats = new ScanStats();
                mScanStats.put(appName, scanStats);
            }
            scanStats.isRegistered = true;
        }
    }

@@ -145,6 +207,7 @@ import java.util.Map;
                App entry = i.next();
                if (entry.uuid.equals(uuid)) {
                    entry.unlinkToDeath();
                    mScanStats.get(entry.name).isRegistered = false;
                    i.remove();
                    break;
                }
@@ -162,6 +225,7 @@ import java.util.Map;
                App entry = i.next();
                if (entry.id == id) {
                    entry.unlinkToDeath();
                    mScanStats.get(entry.name).isRegistered = false;
                    i.remove();
                    break;
                }
@@ -223,6 +287,30 @@ import java.util.Map;
        return null;
    }

    /**
     * Get an application context by the calling Apps name.
     */
    App getByName(String name) {
        Iterator<App> i = mApps.iterator();
        while (i.hasNext()) {
            App entry = i.next();
            if (entry.name.equals(name)) return entry;
        }
        Log.e(TAG, "Context not found for name " + name);
        return null;
    }

    /**
     * Get Logging info by ID
     */
    ScanStats getScanStatsById(int id) {
        App temp = getById(id);
        if (temp != null) {
            return mScanStats.get(temp.name);
        }
        return null;
    }

    /**
     * Get the device addresses for all connected devices
     */
@@ -322,22 +410,86 @@ import java.util.Map;
     * Logs debug information.
     */
    void dump(StringBuilder sb) {
        sb.append("  Entries: " + mApps.size() + "\n");
        long currTime = System.currentTimeMillis();

        Iterator<App> i = mApps.iterator();
        sb.append("  Entries: " + mScanStats.size() + "\n\n");

        Iterator<Map.Entry<String,ScanStats>> i = mScanStats.entrySet().iterator();
        while (i.hasNext()) {
            App entry = i.next();
            List<Connection> connections = getConnectionByApp(entry.id);
            Map.Entry<String, ScanStats> entry = i.next();

            String name = entry.getKey();
            ScanStats scanStats = entry.getValue();

            long maxScanTime = scanStats.maxScanTime;
            long minScanTime = scanStats.minScanTime;
            long currScanTime = 0;

            if (scanStats.isScanning) {
                currScanTime = currTime - scanStats.startTime;
                minScanTime = Math.min(currScanTime, minScanTime);
                maxScanTime = Math.max(currScanTime, maxScanTime);
            }

            if (minScanTime == Long.MAX_VALUE) {
                minScanTime = 0;
            }

            sb.append("\n  Application Id: " + entry.id + "\n");
            sb.append("  UUID: " + entry.uuid + "\n");
            long lastScan = 0;
            if (scanStats.stopTime != 0) {
                lastScan = currTime - scanStats.stopTime;
            }

            long avgScanTime = 0;
            if (scanStats.scansStarted > 0) {
                avgScanTime = (scanStats.totalScanTime + currScanTime) /
                              scanStats.scansStarted;
            }

            sb.append("  Application Name: " + name);
            if (scanStats.isRegistered) sb.append(" (Registered)");
            sb.append("\n");

            sb.append("  LE scans (started/stopped)       : " +
                      scanStats.scansStarted + " / " +
                      scanStats.scansStopped + "\n");
            sb.append("  Scan time in ms (min/max/avg)    : " +
                      minScanTime + " / " +
                      maxScanTime + " / " +
                      avgScanTime + "\n");

            sb.append("  Time since last scan ended in ms : " + lastScan + "\n");

            sb.append("  Last " + scanStats.lastScans.size() +
                      " scans in ms (oldest first): ");
            for (Long time : scanStats.lastScans) {
                sb.append(time + " ");
            }
            sb.append("\n");

            if (scanStats.isRegistered) {
                App appEntry = getByName(name);
                sb.append("  Application ID                   : " +
                          appEntry.id + "\n");
                sb.append("  UUID                             : " +
                          appEntry.uuid + "\n");

                if (scanStats.isScanning) {
                    sb.append("  Current scan duration            : " +
                              currScanTime + "\n");
                }

                List<Connection> connections = getConnectionByApp(appEntry.id);
                sb.append("  Connections: " + connections.size() + "\n");

                Iterator<Connection> ii = connections.iterator();
                while(ii.hasNext()) {
                    Connection connection = ii.next();
                sb.append("    " + connection.connId + ": " + connection.address + "\n");
                    sb.append("    " + connection.connId + ": " +
                              connection.address + "\n");
                }
            }
            sb.append("\n");
        }
    }
}
+4 −2
Original line number Diff line number Diff line
@@ -1389,6 +1389,7 @@ public class GattService extends ProfileService {
        scanClient.hasPeersMacAddressPermission = Utils.checkCallerHasPeersMacAddressPermission(
                this);
        scanClient.legacyForegroundApp = Utils.isLegacyForegroundApp(this, callingPackage);
        mClientMap.getScanStatsById(appIf).startScan();
        mScanManager.startScan(scanClient);
    }

@@ -1403,6 +1404,7 @@ public class GattService extends ProfileService {
        int scanQueueSize = mScanManager.getBatchScanQueue().size() +
                mScanManager.getRegularScanQueue().size();
        if (DBG) Log.d(TAG, "stopScan() - queue size =" + scanQueueSize);
        mClientMap.getScanStatsById(client.clientIf).stopScan();
        mScanManager.stopScan(client);
    }

@@ -1431,7 +1433,7 @@ public class GattService extends ProfileService {
        enforceCallingOrSelfPermission(BLUETOOTH_PERM, "Need BLUETOOTH permission");

        if (DBG) Log.d(TAG, "registerClient() - UUID=" + uuid);
        mClientMap.add(uuid, callback);
        mClientMap.add(uuid, callback, this);
        gattClientRegisterAppNative(uuid.getLeastSignificantBits(),
                                    uuid.getMostSignificantBits());
    }
@@ -1969,7 +1971,7 @@ public class GattService extends ProfileService {
        enforceCallingOrSelfPermission(BLUETOOTH_PERM, "Need BLUETOOTH permission");

        if (DBG) Log.d(TAG, "registerServer() - UUID=" + uuid);
        mServerMap.add(uuid, callback);
        mServerMap.add(uuid, callback, this);
        gattServerRegisterAppNative(uuid.getLeastSignificantBits(),
                                    uuid.getMostSignificantBits());
    }