Merge changes from topic "BLE debug information implementation" (b5921988) · Commits · e / os / android_packages_apps_Bluetooth

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

+290 −104

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,12 +47,18 @@ 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
		mGattService;

		/* Battery stats is used to keep track of scans and result stats */ IBatteryStats mBatteryStats;
		/* Battery stats is used to keep track of scans and result stats */ IBatteryStats
		mBatteryStats;

		class LastScan {
		public long duration;
		@@ -57,25 +66,36 @@ import java.util.List;
		public long suspendStartTime;
		public boolean isSuspended;
		public long timestamp;
		public boolean opportunistic;
		public boolean timeout;
		public boolean background;
		public boolean filtered;
		public boolean isOpportunisticScan;
		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 opportunistic, boolean background,
		boolean filtered, 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.opportunistic = opportunistic;
		this.background = background;
		this.filtered = filtered;
		this.isOpportunisticScan = false;
		this.isTimeout = false;
		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 = "";
		}
		}

		@@ -95,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;
		@@ -147,7 +174,8 @@ import java.util.List;
		return mOngoingScans.get(scannerId);
		}

		synchronized void recordScanStart(ScanSettings settings, boolean filtered, int scannerId) {
		synchronized void recordScanStart(ScanSettings settings, List<ScanFilter> filters,
		boolean isFilterScan, boolean isCallbackScan, int scannerId) {
		LastScan existingScan = getScanFromScannerId(scannerId);
		if (existingScan != null) {
		return;
		@@ -155,11 +183,36 @@ import java.util.List;
		this.mScansStarted++;
		startTime = SystemClock.elapsedRealtime();

		LastScan scan = new LastScan(startTime, 0, false, false, filtered, scannerId);
		LastScan scan = new LastScan(startTime, isFilterScan, isCallbackScan, scannerId,
		settings.getScanMode(), settings.getCallbackType());
		if (settings != null) {
		scan.opportunistic = settings.getScanMode() == ScanSettings.SCAN_MODE_OPPORTUNISTIC;
		scan.background =
		(settings.getCallbackType() & ScanSettings.CALLBACK_TYPE_FIRST_MATCH) != 0;
		scan.isOpportunisticScan = scan.scanMode == ScanSettings.SCAN_MODE_OPPORTUNISTIC;
		scan.isBackgroundScan =
		(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()
		@@ -174,14 +227,15 @@ import java.util.List;
		mScanStartTime = startTime;
		}
		try {
		boolean isUnoptimized = !(scan.filtered \|\| scan.background \|\| scan.opportunistic);
		boolean isUnoptimized =
		!(scan.isFilterScan \|\| scan.isBackgroundScan \|\| scan.isOpportunisticScan);
		mBatteryStats.noteBleScanStarted(mWorkSource, isUnoptimized);
		} catch (RemoteException e) {
		/* ignore */
		}
		StatsLog.write(StatsLog.BLE_SCAN_STATE_CHANGED, mWorkSource,
		StatsLog.BLE_SCAN_STATE_CHANGED__STATE__ON,
		scan.filtered, scan.background, scan.opportunistic);
		scan.isFilterScan, scan.isBackgroundScan, scan.isOpportunisticScan);

		mOngoingScans.put(scannerId, scan);
		}
		@@ -216,16 +270,28 @@ 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 {
		// Inform battery stats of any results it might be missing on scan stop
		boolean isUnoptimized = !(scan.filtered \|\| scan.background \|\| scan.opportunistic);
		boolean isUnoptimized =
		!(scan.isFilterScan \|\| scan.isBackgroundScan \|\| scan.isOpportunisticScan);
		mBatteryStats.noteBleScanResults(mWorkSource, scan.results % 100);
		mBatteryStats.noteBleScanStopped(mWorkSource, isUnoptimized);
		} catch (RemoteException e) {
		@@ -234,7 +300,7 @@ import java.util.List;
		StatsLog.write(StatsLog.BLE_SCAN_RESULT_RECEIVED, mWorkSource, scan.results % 100);
		StatsLog.write(StatsLog.BLE_SCAN_STATE_CHANGED, mWorkSource,
		StatsLog.BLE_SCAN_STATE_CHANGED__STATE__OFF,
		scan.filtered, scan.background, scan.opportunistic);
		scan.isFilterScan, scan.isBackgroundScan, scan.isOpportunisticScan);
		}

		synchronized void recordScanSuspend(int scannerId) {
		@@ -266,7 +332,7 @@ import java.util.List;

		LastScan scan = getScanFromScannerId(scannerId);
		if (scan != null) {
		scan.timeout = true;
		scan.isTimeout = true;
		}
		}

		@@ -304,111 +370,214 @@ 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.opportunistic) {
		sb.append(" (Opportunistic)");
		}
		if (lastScan.background) {
		sb.append(" (Background)");
		}
		if (lastScan.timeout) {
		sb.append(" (Forced-Opportunistic)");
		}
		if (lastScan.filtered) {
		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.opportunistic) {
		if (scan.isOpportunisticScan) {
		sb.append("Opp ");
		}
		if (scan.background) {
		if (scan.isBackgroundScan) {
		sb.append("Back ");
		}
		if (scan.timeout) {
		if (scan.isTimeout) {
		sb.append("Forced ");
		}
		if (scan.filtered) {
		if (scan.isFilterScan) {
		sb.append("Filter ");
		}
		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 ");
		if (scan.opportunistic) {
		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 ");
		}
		if (scan.background) {
		if (scan.isBackgroundScan) {
		sb.append("Back ");
		}
		if (scan.timeout) {
		if (scan.isTimeout) {
		sb.append("Forced ");
		}
		if (scan.filtered) {
		if (scan.isFilterScan) {
		sb.append("Filter ");
		}
		if (scan.isSuspended) {
		@@ -416,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

File changed.

Preview size limit exceeded, changes collapsed.