BLE: GattService debug infomation implementation
Implement GattService debug information.
Bug: 140842714
Test: adb shell dumpsys bluetooth_manager
Change-Id: I8c707873d40edf3e50004aebf10c7104e0b2f745
Merged-In: I8c707873d40edf3e50004aebf10c7104e0b2f745
diff --git a/src/com/android/bluetooth/gatt/AppScanStats.java b/src/com/android/bluetooth/gatt/AppScanStats.java
index 3375b08..a895ece 100644
--- a/src/com/android/bluetooth/gatt/AppScanStats.java
+++ b/src/com/android/bluetooth/gatt/AppScanStats.java
@@ -15,6 +15,7 @@
*/
package com.android.bluetooth.gatt;
+import android.bluetooth.le.ScanFilter;
import android.bluetooth.le.ScanSettings;
import android.os.Binder;
import android.os.RemoteException;
@@ -29,10 +30,12 @@
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.ArrayList;
+import java.util.Arrays;
import java.util.Date;
import java.util.HashMap;
import java.util.Iterator;
import java.util.List;
+import java.util.Objects;
/**
* ScanStats class helps keep track of information about scans
@@ -44,6 +47,11 @@
static final DateFormat DATE_FORMAT = new SimpleDateFormat("MM-dd HH:mm:ss");
+ static final int OPPORTUNISTIC_WEIGHT = 0;
+ static final int LOW_POWER_WEIGHT = 10;
+ static final int BALANCED_WEIGHT = 25;
+ static final int LOW_LATENCY_WEIGHT = 100;
+
/* ContextMap here is needed to grab Apps and Connections */ ContextMap mContextMap;
/* GattService is needed to add scan event protos to be dumped later */ GattService
@@ -62,22 +70,32 @@
public boolean isTimeout;
public boolean isBackgroundScan;
public boolean isFilterScan;
+ public boolean isCallbackScan;
+ public boolean isBatchScan;
public int results;
public int scannerId;
+ public int scanMode;
+ public int scanCallbackType;
+ public String filterString;
- LastScan(long timestamp, long duration, boolean isOpportunisticScan,
- boolean isBackgroundScan, boolean isFilterScan, int scannerId) {
- this.duration = duration;
+ LastScan(long timestamp, boolean isFilterScan, boolean isCallbackScan, int scannerId,
+ int scanMode, int scanCallbackType) {
+ this.duration = 0;
this.timestamp = timestamp;
- this.isOpportunisticScan = isOpportunisticScan;
+ this.isOpportunisticScan = false;
this.isTimeout = false;
- this.isBackgroundScan = isBackgroundScan;
+ this.isBackgroundScan = false;
this.isFilterScan = isFilterScan;
+ this.isCallbackScan = isCallbackScan;
+ this.isBatchScan = false;
+ this.scanMode = scanMode;
+ this.scanCallbackType = scanCallbackType;
this.results = 0;
this.scannerId = scannerId;
this.suspendDuration = 0;
this.suspendStartTime = 0;
this.isSuspended = false;
+ this.filterString = "";
}
}
@@ -97,11 +115,18 @@
private int mScansStarted = 0;
private int mScansStopped = 0;
public boolean isRegistered = false;
- private long mMinScanTime = Long.MAX_VALUE;
- private long mMaxScanTime = 0;
private long mScanStartTime = 0;
- private long mTotalScanTime = 0;
+ private long mTotalActiveTime = 0;
private long mTotalSuspendTime = 0;
+ private long mTotalScanTime = 0;
+ private long mOppScanTime = 0;
+ private long mLowPowerScanTime = 0;
+ private long mBalancedScanTime = 0;
+ private long mLowLantencyScanTime = 0;
+ private int mOppScan = 0;
+ private int mLowPowerScan = 0;
+ private int mBalancedScan = 0;
+ private int mLowLantencyScan = 0;
private List<LastScan> mLastScans = new ArrayList<LastScan>(NUM_SCAN_DURATIONS_KEPT);
private HashMap<Integer, LastScan> mOngoingScans = new HashMap<Integer, LastScan>();
public long startTime = 0;
@@ -149,7 +174,8 @@
return mOngoingScans.get(scannerId);
}
- synchronized void recordScanStart(ScanSettings settings, boolean isFilterScan, int scannerId) {
+ synchronized void recordScanStart(ScanSettings settings, List<ScanFilter> filters,
+ boolean isFilterScan, boolean isCallbackScan, int scannerId) {
LastScan existingScan = getScanFromScannerId(scannerId);
if (existingScan != null) {
return;
@@ -157,12 +183,36 @@
this.mScansStarted++;
startTime = SystemClock.elapsedRealtime();
- LastScan scan = new LastScan(startTime, 0, false, false, isFilterScan, scannerId);
+ LastScan scan = new LastScan(startTime, isFilterScan, isCallbackScan, scannerId,
+ settings.getScanMode(), settings.getCallbackType());
if (settings != null) {
- scan.isOpportunisticScan =
- settings.getScanMode() == ScanSettings.SCAN_MODE_OPPORTUNISTIC;
+ scan.isOpportunisticScan = scan.scanMode == ScanSettings.SCAN_MODE_OPPORTUNISTIC;
scan.isBackgroundScan =
- (settings.getCallbackType() & ScanSettings.CALLBACK_TYPE_FIRST_MATCH) != 0;
+ (scan.scanCallbackType & ScanSettings.CALLBACK_TYPE_FIRST_MATCH) != 0;
+ scan.isBatchScan =
+ settings.getCallbackType() == ScanSettings.CALLBACK_TYPE_ALL_MATCHES
+ && settings.getReportDelayMillis() != 0;
+ switch (scan.scanMode) {
+ case ScanSettings.SCAN_MODE_OPPORTUNISTIC:
+ mOppScan++;
+ break;
+ case ScanSettings.SCAN_MODE_LOW_POWER:
+ mLowPowerScan++;
+ break;
+ case ScanSettings.SCAN_MODE_BALANCED:
+ mBalancedScan++;
+ break;
+ case ScanSettings.SCAN_MODE_LOW_LATENCY:
+ mLowLantencyScan++;
+ break;
+ }
+ }
+
+ if (isFilterScan) {
+ for (ScanFilter filter : filters) {
+ scan.filterString +=
+ "\n └ " + filterToStringWithoutNullParam(filter);
+ }
}
BluetoothMetricsProto.ScanEvent scanEvent = BluetoothMetricsProto.ScanEvent.newBuilder()
@@ -220,11 +270,22 @@
.build();
mGattService.addScanEvent(scanEvent);
- if (!isScanning()) {
- long totalDuration = stopTime - mScanStartTime;
- mTotalScanTime += totalDuration;
- mMinScanTime = Math.min(totalDuration, mMinScanTime);
- mMaxScanTime = Math.max(totalDuration, mMaxScanTime);
+ mTotalScanTime += scanDuration;
+ long activeDuration = scanDuration - scan.suspendDuration;
+ mTotalActiveTime += activeDuration;
+ switch (scan.scanMode) {
+ case ScanSettings.SCAN_MODE_OPPORTUNISTIC:
+ mOppScanTime += activeDuration;
+ break;
+ case ScanSettings.SCAN_MODE_LOW_POWER:
+ mLowPowerScanTime += activeDuration;
+ break;
+ case ScanSettings.SCAN_MODE_BALANCED:
+ mBalancedScanTime += activeDuration;
+ break;
+ case ScanSettings.SCAN_MODE_LOW_LATENCY:
+ mLowLantencyScanTime += activeDuration;
+ break;
}
try {
@@ -309,72 +370,158 @@
return initiator;
}
+ private static String filterToStringWithoutNullParam(ScanFilter filter) {
+ String filterString = "BluetoothLeScanFilter [";
+ if (filter.getDeviceName() != null) {
+ filterString += " DeviceName=" + filter.getDeviceName();
+ }
+ if (filter.getDeviceAddress() != null) {
+ filterString += " DeviceAddress=" + filter.getDeviceAddress();
+ }
+ if (filter.getServiceUuid() != null) {
+ filterString += " ServiceUuid=" + filter.getServiceUuid();
+ }
+ if (filter.getServiceUuidMask() != null) {
+ filterString += " ServiceUuidMask=" + filter.getServiceUuidMask();
+ }
+ if (filter.getServiceSolicitationUuid() != null) {
+ filterString += " ServiceSolicitationUuid=" + filter.getServiceSolicitationUuid();
+ }
+ if (filter.getServiceSolicitationUuidMask() != null) {
+ filterString +=
+ " ServiceSolicitationUuidMask=" + filter.getServiceSolicitationUuidMask();
+ }
+ if (filter.getServiceDataUuid() != null) {
+ filterString += " ServiceDataUuid=" + Objects.toString(filter.getServiceDataUuid());
+ }
+ if (filter.getServiceData() != null) {
+ filterString += " ServiceData=" + Arrays.toString(filter.getServiceData());
+ }
+ if (filter.getServiceDataMask() != null) {
+ filterString += " ServiceDataMask=" + Arrays.toString(filter.getServiceDataMask());
+ }
+ if (filter.getManufacturerId() >= 0) {
+ filterString += " ManufacturerId=" + filter.getManufacturerId();
+ }
+ if (filter.getManufacturerData() != null) {
+ filterString += " ManufacturerData=" + Arrays.toString(filter.getManufacturerData());
+ }
+ if (filter.getManufacturerDataMask() != null) {
+ filterString +=
+ " ManufacturerDataMask=" + Arrays.toString(filter.getManufacturerDataMask());
+ }
+ filterString += " ]";
+ return filterString;
+ }
+
+
+ private static String scanModeToString(int scanMode) {
+ switch (scanMode) {
+ case ScanSettings.SCAN_MODE_OPPORTUNISTIC:
+ return "OPPORTUNISTIC";
+ case ScanSettings.SCAN_MODE_LOW_LATENCY:
+ return "LOW_LATENCY";
+ case ScanSettings.SCAN_MODE_BALANCED:
+ return "BALANCED";
+ case ScanSettings.SCAN_MODE_LOW_POWER:
+ return "LOW_POWER";
+ default:
+ return "UNKNOWN(" + scanMode + ")";
+ }
+ }
+
+ private static String callbackTypeToString(int callbackType) {
+ switch (callbackType) {
+ case ScanSettings.CALLBACK_TYPE_ALL_MATCHES:
+ return "ALL_MATCHES";
+ case ScanSettings.CALLBACK_TYPE_FIRST_MATCH:
+ return "FIRST_MATCH";
+ case ScanSettings.CALLBACK_TYPE_MATCH_LOST:
+ return "LOST";
+ default:
+ return callbackType == (ScanSettings.CALLBACK_TYPE_FIRST_MATCH
+ | ScanSettings.CALLBACK_TYPE_MATCH_LOST) ? "[FIRST_MATCH | LOST]" : "UNKNOWN: "
+ + callbackType;
+ }
+ }
+
synchronized void dumpToString(StringBuilder sb) {
+ long currentTime = System.currentTimeMillis();
long currTime = SystemClock.elapsedRealtime();
- long maxScan = mMaxScanTime;
- long minScan = mMinScanTime;
+ long Score = 0;
long scanDuration = 0;
+ long suspendDuration = 0;
+ long activeDuration = 0;
+ long totalActiveTime = mTotalActiveTime;
+ long totalSuspendTime = mTotalSuspendTime;
+ long totalScanTime = mTotalScanTime;
+ long oppScanTime = mOppScanTime;
+ long lowPowerScanTime = mLowPowerScanTime;
+ long balancedScanTime = mBalancedScanTime;
+ long lowLatencyScanTime = mLowLantencyScanTime;
+ int oppScan = mOppScan;
+ int lowPowerScan = mLowPowerScan;
+ int balancedScan = mBalancedScan;
+ int lowLatencyScan = mLowLantencyScan;
- if (isScanning()) {
- scanDuration = currTime - mScanStartTime;
- }
- minScan = Math.min(scanDuration, minScan);
- maxScan = Math.max(scanDuration, maxScan);
+ if (!mOngoingScans.isEmpty()) {
+ for (Integer key : mOngoingScans.keySet()) {
+ LastScan scan = mOngoingScans.get(key);
+ scanDuration = currTime - scan.timestamp;
- if (minScan == Long.MAX_VALUE) {
- minScan = 0;
- }
+ if (scan.isSuspended) {
+ suspendDuration = currTime - scan.suspendStartTime;
+ totalSuspendTime += suspendDuration;
+ }
- /*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 (mScansStarted > 0) {
- avgScan = totalScanTime / mScansStarted;
+ totalScanTime += scanDuration;
+ totalSuspendTime += suspendDuration;
+ activeDuration = scanDuration - scan.suspendDuration - suspendDuration;
+ totalActiveTime += activeDuration;
+ switch (scan.scanMode) {
+ case ScanSettings.SCAN_MODE_OPPORTUNISTIC:
+ oppScanTime += activeDuration;
+ break;
+ case ScanSettings.SCAN_MODE_LOW_POWER:
+ lowPowerScanTime += activeDuration;
+ break;
+ case ScanSettings.SCAN_MODE_BALANCED:
+ balancedScanTime += activeDuration;
+ break;
+ case ScanSettings.SCAN_MODE_LOW_LATENCY:
+ lowLatencyScanTime += activeDuration;
+ break;
+ }
+ }
}
+ Score = (oppScanTime * OPPORTUNISTIC_WEIGHT + lowPowerScanTime * LOW_POWER_WEIGHT
+ + balancedScanTime * BALANCED_WEIGHT + lowLatencyScanTime * LOW_LATENCY_WEIGHT) / 100;
sb.append(" " + appName);
if (isRegistered) {
sb.append(" (Registered)");
}
- if (!mLastScans.isEmpty()) {
- LastScan lastScan = mLastScans.get(mLastScans.size() - 1);
- if (lastScan.isOpportunisticScan) {
- sb.append(" (Opportunistic)");
- }
- if (lastScan.isBackgroundScan) {
- sb.append(" (Background)");
- }
- if (lastScan.isTimeout) {
- sb.append(" (Forced-Opportunistic)");
- }
- if (lastScan.isFilterScan) {
- sb.append(" (Filtered)");
- }
- }
- sb.append("\n");
+ sb.append("\n LE scans (started/stopped) : "
+ + mScansStarted + " / " + mScansStopped);
+ sb.append("\n Scan time in ms (active/suspend/total) : "
+ + totalActiveTime + " / " + totalSuspendTime + " / " + totalScanTime);
+ sb.append("\n Scan time with mode in ms (Opp/LowPower/Balanced/LowLatency): "
+ + oppScanTime + " / " + lowPowerScanTime + " / " + balancedScanTime + " / "
+ + lowLatencyScanTime);
+ sb.append("\n Scan mode counter (Opp/LowPower/Balanced/LowLatency) : " + oppScan
+ + " / " + lowPowerScan + " / " + balancedScan + " / " + lowLatencyScan);
+ sb.append("\n Score : " + Score);
+ sb.append("\n Total number of results : " + results);
- sb.append(" LE scans (started/stopped) : " + mScansStarted + " / " + mScansStopped
- + "\n");
- sb.append(" Scan time in ms (min/max/avg/total): " + minScan + " / " + maxScan + " / "
- + avgScan + " / " + totalScanTime + "\n");
- if (mTotalSuspendTime != 0) {
- sb.append(" Total time suspended : " + mTotalSuspendTime + "ms\n");
- }
- sb.append(" Total number of results : " + results + "\n");
-
- long currentTime = System.currentTimeMillis();
- long elapsedRt = SystemClock.elapsedRealtime();
if (!mLastScans.isEmpty()) {
- sb.append(" Last " + mLastScans.size() + " scans :\n");
+ sb.append("\n Last " + mLastScans.size()
+ + " scans :");
for (int i = 0; i < mLastScans.size(); i++) {
LastScan scan = mLastScans.get(i);
- Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);
- sb.append(" " + DATE_FORMAT.format(timestamp) + " - ");
+ Date timestamp = new Date(currentTime - currTime + scan.timestamp);
+ sb.append("\n " + DATE_FORMAT.format(timestamp) + " - ");
sb.append(scan.duration + "ms ");
if (scan.isOpportunisticScan) {
sb.append("Opp ");
@@ -389,21 +536,38 @@
sb.append("Filter ");
}
sb.append(scan.results + " results");
- sb.append(" (" + scan.scannerId + ")");
- sb.append("\n");
+ sb.append(" (" + scan.scannerId + ") ");
+ if (scan.isCallbackScan) {
+ sb.append("CB ");
+ } else {
+ sb.append("PI ");
+ }
+ if (scan.isBatchScan) {
+ sb.append("Batch Scan");
+ } else {
+ sb.append("Regular Scan");
+ }
if (scan.suspendDuration != 0) {
- sb.append(" └" + " Suspended Time: " + scan.suspendDuration + "ms\n");
+ activeDuration = scan.duration - scan.suspendDuration;
+ sb.append("\n └ " + "Suspended Time: " + scan.suspendDuration
+ + "ms, Active Time: " + activeDuration);
+ }
+ sb.append("\n └ " + "Scan Config: [ ScanMode="
+ + scanModeToString(scan.scanMode) + ", callbackType="
+ + callbackTypeToString(scan.scanCallbackType) + " ]");
+ if (scan.isFilterScan) {
+ sb.append(scan.filterString);
}
}
}
if (!mOngoingScans.isEmpty()) {
- sb.append(" Ongoing scans :\n");
+ sb.append("\n Ongoing scans :");
for (Integer key : mOngoingScans.keySet()) {
LastScan scan = mOngoingScans.get(key);
- Date timestamp = new Date(currentTime - elapsedRt + scan.timestamp);
- sb.append(" " + DATE_FORMAT.format(timestamp) + " - ");
- sb.append((elapsedRt - scan.timestamp) + "ms ");
+ Date timestamp = new Date(currentTime - currTime + scan.timestamp);
+ sb.append("\n " + DATE_FORMAT.format(timestamp) + " - ");
+ sb.append((currTime - scan.timestamp) + "ms ");
if (scan.isOpportunisticScan) {
sb.append("Opp ");
}
@@ -420,35 +584,52 @@
sb.append("Suspended ");
}
sb.append(scan.results + " results");
- sb.append(" (" + scan.scannerId + ")");
- sb.append("\n");
+ sb.append(" (" + scan.scannerId + ") ");
+ if (scan.isCallbackScan) {
+ sb.append("CB ");
+ } else {
+ sb.append("PI ");
+ }
+ if (scan.isBatchScan) {
+ sb.append("Batch Scan");
+ } else {
+ sb.append("Regular Scan");
+ }
if (scan.suspendStartTime != 0) {
- long duration = scan.suspendDuration + (scan.isSuspended ? (elapsedRt
+ long duration = scan.suspendDuration + (scan.isSuspended ? (currTime
- scan.suspendStartTime) : 0);
- sb.append(" └" + " Suspended Time: " + duration + "ms\n");
+ activeDuration = scan.duration - scan.suspendDuration;
+ sb.append("\n └ " + "Suspended Time:" + scan.suspendDuration
+ + "ms, Active Time:" + activeDuration);
+ }
+ sb.append("\n └ " + "Scan Config: [ ScanMode="
+ + scanModeToString(scan.scanMode) + ", callbackType="
+ + callbackTypeToString(scan.scanCallbackType) + " ]");
+ if (scan.isFilterScan) {
+ sb.append(scan.filterString);
}
}
}
ContextMap.App appEntry = mContextMap.getByName(appName);
if (appEntry != null && isRegistered) {
- sb.append(" Application ID : " + appEntry.id + "\n");
- sb.append(" UUID : " + appEntry.uuid + "\n");
+ sb.append("\n Application ID : " + appEntry.id);
+ sb.append("\n UUID : " + appEntry.uuid);
List<ContextMap.Connection> connections = mContextMap.getConnectionByApp(appEntry.id);
- sb.append(" Connections: " + connections.size() + "\n");
+ sb.append("\n Connections: " + connections.size());
Iterator<ContextMap.Connection> ii = connections.iterator();
while (ii.hasNext()) {
ContextMap.Connection connection = ii.next();
- long connectionTime = elapsedRt - connection.startTime;
- Date timestamp = new Date(currentTime - elapsedRt + connection.startTime);
- sb.append(" " + DATE_FORMAT.format(timestamp) + " - ");
+ long connectionTime = currTime - connection.startTime;
+ Date timestamp = new Date(currentTime - currTime + connection.startTime);
+ sb.append("\n " + DATE_FORMAT.format(timestamp) + " - ");
sb.append((connectionTime) + "ms ");
- sb.append(": " + connection.address + " (" + connection.connId + ")\n");
+ sb.append(": " + connection.address + " (" + connection.connId + ")");
}
}
- sb.append("\n");
+ sb.append("\n\n");
}
}
diff --git a/src/com/android/bluetooth/gatt/GattService.java b/src/com/android/bluetooth/gatt/GattService.java
index 42c0bd7..5f2b42e 100644
--- a/src/com/android/bluetooth/gatt/GattService.java
+++ b/src/com/android/bluetooth/gatt/GattService.java
@@ -1961,10 +1961,15 @@
Utils.checkCallerHasNetworkSetupWizardPermission(this);
AppScanStats app = mScannerMap.getAppScanStatsById(scannerId);
+ ScannerMap.App cbApp = mScannerMap.getById(scannerId);
if (app != null) {
scanClient.stats = app;
boolean isFilteredScan = (filters != null) && !filters.isEmpty();
- app.recordScanStart(settings, isFilteredScan, scannerId);
+ boolean isCallbackScan = false;
+ if (cbApp != null) {
+ isCallbackScan = cbApp.callback != null;
+ }
+ app.recordScanStart(settings, filters, isFilteredScan, isCallbackScan, scannerId);
}
mScanManager.startScan(scanClient);
@@ -2033,7 +2038,8 @@
if (scanStats != null) {
scanClient.stats = scanStats;
boolean isFilteredScan = (piInfo.filters != null) && !piInfo.filters.isEmpty();
- scanStats.recordScanStart(piInfo.settings, isFilteredScan, scannerId);
+ scanStats.recordScanStart(
+ piInfo.settings, piInfo.filters, isFilteredScan, false, scannerId);
}
mScanManager.startScan(scanClient);
@@ -3169,6 +3175,22 @@
return uuids;
}
+ void dumpRegisterId(StringBuilder sb) {
+ sb.append(" Scanner:\n");
+ for (Integer appId : mScannerMap.getAllAppsIds()) {
+ println(sb, " app_if: " + appId + ", appName: " + mScannerMap.getById(appId).name);
+ }
+ sb.append(" Client:\n");
+ for (Integer appId : mClientMap.getAllAppsIds()) {
+ println(sb, " app_if: " + appId + ", appName: " + mClientMap.getById(appId).name);
+ }
+ sb.append(" Server:\n");
+ for (Integer appId : mServerMap.getAllAppsIds()) {
+ println(sb, " app_if: " + appId + ", appName: " + mServerMap.getById(appId).name);
+ }
+ sb.append("\n\n");
+ }
+
@Override
public void dump(StringBuilder sb) {
super.dump(sb);
@@ -3179,7 +3201,10 @@
println(sb, "mMaxScanFilters: " + mMaxScanFilters);
- sb.append("\nGATT Scanner Map\n");
+ sb.append("\nRegistered App\n");
+ dumpRegisterId(sb);
+
+ sb.append("GATT Scanner Map\n");
mScannerMap.dump(sb);
sb.append("GATT Client Map\n");
