BLE: GattService debug infomation implementation (70569eb5) · Commits · e / os / android_packages_apps_Bluetooth

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

+266 −85

Original line number	Diff line number	Diff line
		@@ -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 com.android.internal.app.IBatteryStats;
		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 @@ import java.util.List;

		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 @@ import java.util.List;
		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 @@ import java.util.List;
		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 @@ import java.util.List;
		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 @@ import java.util.List;
		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 @@ import java.util.List;
		.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 @@ import java.util.List;
		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(" 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");
		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);

		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 ");
		@@ -390,20 +537,37 @@ import java.util.List;
		}
		sb.append(scan.results + " results");
		sb.append(" (" + scan.scannerId + ") ");
		sb.append("\n");
		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 ");
		}
		@@ -421,34 +585,51 @@ import java.util.List;
		}
		sb.append(scan.results + " results");
		sb.append(" (" + scan.scannerId + ") ");
		sb.append("\n");
		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");
		}
		}

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

+28 −3

Original line number	Diff line number	Diff line
		@@ -1961,10 +1961,15 @@ public class GattService extends ProfileService {
		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 @@ public class GattService extends ProfileService {
		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 @@ public class GattService extends ProfileService {
		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 @@ public class GattService extends ProfileService {

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