From 7fc66d2c009ed005371ab8b23b219b1cb3e19169 Mon Sep 17 00:00:00 2001 From: Jayden Kim <jaydenk@google.com> Date: Mon, 19 Sep 2022 04:35:35 +0000 Subject: [PATCH] Fix Bluetooth LE advertising logger for enableAdvertisingSet - records enable/disable AdvertisingSet Correctly - handles advertising disabled events by duration timeout (status is 60) Bug: 213610155 Tag: #stability Test: manual test with test app and adb shell dumpsys bluetooth_manager Change-Id: I1ac5b56fe85cc06201c1346f4266ad0ff9d4e7bc --- .../bluetooth/gatt/AdvertiseManager.java | 39 +++++--- .../bluetooth/gatt/AppAdvertiseStats.java | 91 ++++++++++--------- .../android/bluetooth/gatt/ContextMap.java | 7 +- .../android/bluetooth/gatt/GattService.java | 6 +- 4 files changed, 79 insertions(+), 64 deletions(-) diff --git a/android/app/src/com/android/bluetooth/gatt/AdvertiseManager.java b/android/app/src/com/android/bluetooth/gatt/AdvertiseManager.java index af2290788ad..4ba889dbbcb 100644 --- a/android/app/src/com/android/bluetooth/gatt/AdvertiseManager.java +++ b/android/app/src/com/android/bluetooth/gatt/AdvertiseManager.java @@ -30,6 +30,7 @@ import android.os.RemoteException; import android.util.Log; import com.android.bluetooth.btservice.AdapterService; +import com.android.bluetooth.gatt.GattService.AdvertiserMap; import java.util.Collections; import java.util.HashMap; @@ -46,6 +47,7 @@ class AdvertiseManager { private final GattService mService; private final AdapterService mAdapterService; + private final AdvertiserMap mAdvertiserMap; private Handler mHandler; Map<IBinder, AdvertiserInfo> mAdvertisers = Collections.synchronizedMap(new HashMap<>()); static int sTempRegistrationId = -1; @@ -53,12 +55,14 @@ class AdvertiseManager { /** * Constructor of {@link AdvertiseManager}. */ - AdvertiseManager(GattService service, AdapterService adapterService) { + AdvertiseManager(GattService service, AdapterService adapterService, + AdvertiserMap advertiserMap) { if (DBG) { Log.d(TAG, "advertise manager created"); } mService = service; mAdapterService = adapterService; + mAdvertiserMap = advertiserMap; } /** @@ -158,17 +162,17 @@ class AdvertiseManager { entry.setValue( new AdvertiserInfo(advertiserId, entry.getValue().deathRecipient, callback)); - mService.mAdvertiserMap.setAdvertiserIdByRegId(regId, advertiserId); + mAdvertiserMap.setAdvertiserIdByRegId(regId, advertiserId); } else { IBinder binder = entry.getKey(); binder.unlinkToDeath(entry.getValue().deathRecipient, 0); mAdvertisers.remove(binder); - AppAdvertiseStats stats = mService.mAdvertiserMap.getAppAdvertiseStatsById(regId); + AppAdvertiseStats stats = mAdvertiserMap.getAppAdvertiseStatsById(regId); if (stats != null) { stats.recordAdvertiseStop(); } - mService.mAdvertiserMap.removeAppAdvertiseStats(regId); + mAdvertiserMap.removeAppAdvertiseStats(regId); } callback.onAdvertisingSetStarted(advertiserId, txPower, status); @@ -189,6 +193,13 @@ class AdvertiseManager { IAdvertisingSetCallback callback = entry.getValue().callback; callback.onAdvertisingEnabled(advertiserId, enable, status); + + if (!enable && status != 0) { + AppAdvertiseStats stats = mAdvertiserMap.getAppAdvertiseStatsById(advertiserId); + if (stats != null) { + stats.recordAdvertiseStop(); + } + } } void startAdvertisingSet(AdvertisingSetParameters parameters, AdvertiseData advertiseData, @@ -218,8 +229,8 @@ class AdvertiseManager { Log.d(TAG, "startAdvertisingSet() - reg_id=" + cbId + ", callback: " + binder); } - mService.mAdvertiserMap.add(cbId, callback, mService); - mService.mAdvertiserMap.recordAdvertiseStart(cbId, parameters, advertiseData, + mAdvertiserMap.add(cbId, callback, mService); + mAdvertiserMap.recordAdvertiseStart(cbId, parameters, advertiseData, scanResponse, periodicParameters, periodicData, duration, maxExtAdvEvents); startAdvertisingSetNative(parameters, advDataBytes, scanResponseBytes, @@ -290,7 +301,7 @@ class AdvertiseManager { Log.i(TAG, "error sending onAdvertisingSetStopped callback", e); } - mService.mAdvertiserMap.recordAdvertiseStop(advertiserId); + mAdvertiserMap.recordAdvertiseStop(advertiserId); } void enableAdvertisingSet(int advertiserId, boolean enable, int duration, int maxExtAdvEvents) { @@ -301,7 +312,7 @@ class AdvertiseManager { } enableAdvertisingSetNative(advertiserId, enable, duration, maxExtAdvEvents); - mService.mAdvertiserMap.enableAdvertisingSet(advertiserId, + mAdvertiserMap.enableAdvertisingSet(advertiserId, enable, duration, maxExtAdvEvents); } @@ -316,7 +327,7 @@ class AdvertiseManager { setAdvertisingDataNative(advertiserId, AdvertiseHelper.advertiseDataToBytes(data, deviceName)); - mService.mAdvertiserMap.setAdvertisingData(advertiserId, data); + mAdvertiserMap.setAdvertisingData(advertiserId, data); } catch (IllegalArgumentException e) { try { onAdvertisingDataSet(advertiserId, @@ -338,7 +349,7 @@ class AdvertiseManager { setScanResponseDataNative(advertiserId, AdvertiseHelper.advertiseDataToBytes(data, deviceName)); - mService.mAdvertiserMap.setScanResponseData(advertiserId, data); + mAdvertiserMap.setScanResponseData(advertiserId, data); } catch (IllegalArgumentException e) { try { onScanResponseDataSet(advertiserId, @@ -357,7 +368,7 @@ class AdvertiseManager { } setAdvertisingParametersNative(advertiserId, parameters); - mService.mAdvertiserMap.setAdvertisingParameters(advertiserId, parameters); + mAdvertiserMap.setAdvertisingParameters(advertiserId, parameters); } void setPeriodicAdvertisingParameters(int advertiserId, @@ -369,7 +380,7 @@ class AdvertiseManager { } setPeriodicAdvertisingParametersNative(advertiserId, parameters); - mService.mAdvertiserMap.setPeriodicAdvertisingParameters(advertiserId, parameters); + mAdvertiserMap.setPeriodicAdvertisingParameters(advertiserId, parameters); } void setPeriodicAdvertisingData(int advertiserId, AdvertiseData data) { @@ -383,7 +394,7 @@ class AdvertiseManager { setPeriodicAdvertisingDataNative(advertiserId, AdvertiseHelper.advertiseDataToBytes(data, deviceName)); - mService.mAdvertiserMap.setPeriodicAdvertisingData(advertiserId, data); + mAdvertiserMap.setPeriodicAdvertisingData(advertiserId, data); } catch (IllegalArgumentException e) { try { onPeriodicAdvertisingDataSet(advertiserId, @@ -502,7 +513,7 @@ class AdvertiseManager { IAdvertisingSetCallback callback = entry.getValue().callback; callback.onPeriodicAdvertisingEnabled(advertiserId, enable, status); - AppAdvertiseStats stats = mService.mAdvertiserMap.getAppAdvertiseStatsById(advertiserId); + AppAdvertiseStats stats = mAdvertiserMap.getAppAdvertiseStatsById(advertiserId); if (stats != null) { stats.onPeriodicAdvertiseEnabled(enable); } diff --git a/android/app/src/com/android/bluetooth/gatt/AppAdvertiseStats.java b/android/app/src/com/android/bluetooth/gatt/AppAdvertiseStats.java index 3592875ea4a..13241498cfb 100644 --- a/android/app/src/com/android/bluetooth/gatt/AppAdvertiseStats.java +++ b/android/app/src/com/android/bluetooth/gatt/AppAdvertiseStats.java @@ -20,13 +20,13 @@ import android.bluetooth.le.AdvertiseData; import android.bluetooth.le.AdvertisingSetParameters; import android.bluetooth.le.PeriodicAdvertisingParameters; import android.os.ParcelUuid; -import android.os.SystemClock; import android.util.SparseArray; -import java.text.DateFormat; -import java.text.SimpleDateFormat; -import java.util.Date; -import java.util.LinkedList; +import java.time.Duration; +import java.time.Instant; +import java.time.ZoneId; +import java.time.format.DateTimeFormatter; +import java.util.ArrayList; import java.util.List; import java.util.Map; @@ -38,9 +38,11 @@ import java.util.Map; /*package*/ class AppAdvertiseStats { private static final String TAG = AppAdvertiseStats.class.getSimpleName(); - static final DateFormat DATE_FORMAT = new SimpleDateFormat("MM-dd HH:mm:ss"); + private static DateTimeFormatter sDateFormat = DateTimeFormatter.ofPattern("MM-dd HH:mm:ss") + .withZone(ZoneId.systemDefault()); static final String[] PHY_LE_STRINGS = {"LE_1M", "LE_2M", "LE_CODED"}; + static final int UUID_STRING_FILTER_LEN = 8; // ContextMap here is needed to grab Apps and Connections ContextMap mContextMap; @@ -48,7 +50,7 @@ import java.util.Map; // GattService is needed to add scan event protos to be dumped later GattService mGattService; - class AppAdvertiserData { + static class AppAdvertiserData { public boolean includeDeviceName = false; public boolean includeTxPowerLevel = false; public SparseArray<byte[]> manufacturerData; @@ -65,12 +67,12 @@ import java.util.Map; } } - class AppAdvertiserRecord { - public long startTime = 0; - public long stopTime = 0; + static class AppAdvertiserRecord { + public Instant startTime = null; + public Instant stopTime = null; public int duration = 0; public int maxExtendedAdvertisingEvents = 0; - AppAdvertiserRecord(long startTime) { + AppAdvertiserRecord(Instant startTime) { this.startTime = startTime; } } @@ -93,8 +95,8 @@ import java.util.Map; private AppAdvertiserData mPeriodicAdvertisingData = null; private boolean mPeriodicIncludeTxPower = false; private int mPeriodicInterval = 0; - public LinkedList<AppAdvertiserRecord> mAdvertiserRecords = - new LinkedList<AppAdvertiserRecord>(); + public ArrayList<AppAdvertiserRecord> mAdvertiserRecords = + new ArrayList<AppAdvertiserRecord>(); AppAdvertiseStats(int appUid, int id, String name, ContextMap map, GattService service) { this.mAppUid = appUid; @@ -109,10 +111,14 @@ import java.util.Map; PeriodicAdvertisingParameters periodicParameters, AdvertiseData periodicData, int duration, int maxExtAdvEvents) { mAdvertisingEnabled = true; - AppAdvertiserRecord record = new AppAdvertiserRecord(SystemClock.elapsedRealtime()); + AppAdvertiserRecord record = new AppAdvertiserRecord(Instant.now()); record.duration = duration; record.maxExtendedAdvertisingEvents = maxExtAdvEvents; mAdvertiserRecords.add(record); + if (mAdvertiserRecords.size() > 5) { + mAdvertiserRecords.remove(0); + } + if (parameters != null) { mPrimaryPhy = parameters.getPrimaryPhy(); mSecondaryPhy = parameters.getSecondaryPhy(); @@ -156,29 +162,29 @@ import java.util.Map; } } + void recordAdvertiseStart(int duration, int maxExtAdvEvents) { + recordAdvertiseStart(null, null, null, null, null, duration, maxExtAdvEvents); + } + void recordAdvertiseStop() { mAdvertisingEnabled = false; mPeriodicAdvertisingEnabled = false; - AppAdvertiserRecord record = mAdvertiserRecords.getLast(); - record.stopTime = SystemClock.elapsedRealtime(); + if (!mAdvertiserRecords.isEmpty()) { + AppAdvertiserRecord record = mAdvertiserRecords.get(mAdvertiserRecords.size() - 1); + record.stopTime = Instant.now(); + } } void enableAdvertisingSet(boolean enable, int duration, int maxExtAdvEvents) { - AppAdvertiserRecord lastRecord = mAdvertiserRecords.getLast(); - if (mAdvertisingEnabled) { + if (enable) { //if the advertisingSet have not been disabled, skip enabling. - if (lastRecord.stopTime != 0) { - AppAdvertiserRecord record = new AppAdvertiserRecord(SystemClock.elapsedRealtime()); - record.duration = duration; - record.maxExtendedAdvertisingEvents = maxExtAdvEvents; - mAdvertiserRecords.add(record); - if (mAdvertiserRecords.size() > 5) { - mAdvertiserRecords.removeFirst(); - } + if (!mAdvertisingEnabled) { + recordAdvertiseStart(duration, maxExtAdvEvents); } } else { - if (lastRecord.stopTime == 0) { - lastRecord.stopTime = SystemClock.elapsedRealtime(); + //if the advertisingSet have not been enabled, skip disabling. + if (mAdvertisingEnabled) { + recordAdvertiseStop(); } } } @@ -274,24 +280,23 @@ import java.util.Map; + advData.includeTxPowerLevel); if (advData.manufacturerData.size() > 0) { - sb.append("\n â””Manufacturer Data : "); - for (int i = 0; i < advData.manufacturerData.size(); i++) { - sb.append("\n [" + Integer.toHexString(advData.manufacturerData.keyAt(i)) - + ", " + printByteArrayInHex(advData.manufacturerData.valueAt(i)) + "]"); - } + sb.append("\n â””Manufacturer Data (length of data) : " + + advData.manufacturerData.size()); } if (!advData.serviceData.isEmpty()) { sb.append("\n â””Service Data(UUID, length of data) : "); for (ParcelUuid uuid : advData.serviceData.keySet()) { - sb.append("\n [" + uuid + ", " + sb.append("\n [" + uuid.toString().substring(0, UUID_STRING_FILTER_LEN) + + "-xxxx-xxxx-xxxx-xxxxxxxxxxxx, " + advData.serviceData.get(uuid).length + "]"); } } if (!advData.serviceUuids.isEmpty()) { sb.append("\n â””Service Uuids : \n " - + advData.serviceUuids.toString()); + + advData.serviceUuids.toString().substring(0, UUID_STRING_FILTER_LEN) + + "-xxxx-xxxx-xxxx-xxxxxxxxxxxx"); } } @@ -350,28 +355,24 @@ import java.util.Map; } static void dumpToString(StringBuilder sb, AppAdvertiseStats stats) { - long currentTime = System.currentTimeMillis(); - long currentRealTime = SystemClock.elapsedRealtime(); + Instant currentTime = Instant.now(); sb.append("\n " + stats.mAppName); sb.append("\n Advertising ID : " + stats.mId); for (int i = 0; i < stats.mAdvertiserRecords.size(); i++) { AppAdvertiserRecord record = stats.mAdvertiserRecords.get(i); - Date timestamp = new Date(currentTime - currentRealTime - + record.startTime); sb.append("\n " + (i + 1) + ":"); sb.append("\n â””Start time : " - + DATE_FORMAT.format(timestamp)); - if (record.stopTime == 0) { + + sDateFormat.format(record.startTime)); + if (record.stopTime == null) { + Duration timeElapsed = Duration.between(record.startTime, currentTime); sb.append("\n â””Elapsed time : " - + (currentRealTime - record.startTime) + "ms"); + + timeElapsed.toMillis() + "ms"); } else { - Date stopTimestamp = new Date(currentTime - currentRealTime - + record.stopTime); sb.append("\n â””Stop time : " - + DATE_FORMAT.format(stopTimestamp)); + + sDateFormat.format(record.stopTime)); } sb.append("\n â””Duration(10ms unit) : " + record.duration); diff --git a/android/app/src/com/android/bluetooth/gatt/ContextMap.java b/android/app/src/com/android/bluetooth/gatt/ContextMap.java index 381a1e5635c..f9c6cd4d44b 100644 --- a/android/app/src/com/android/bluetooth/gatt/ContextMap.java +++ b/android/app/src/com/android/bluetooth/gatt/ContextMap.java @@ -27,6 +27,8 @@ import android.os.UserHandle; import android.os.WorkSource; import android.util.Log; +import com.android.internal.annotations.GuardedBy; + import com.google.common.collect.EvictingQueue; import java.util.ArrayList; @@ -183,8 +185,9 @@ import java.util.UUID; } /** Our internal application list */ - private List<App> mApps = new ArrayList<App>(); private final Object mAppsLock = new Object(); + @GuardedBy("mAppsLock") + private List<App> mApps = new ArrayList<App>(); /** Internal map to keep track of logging information by app name */ private HashMap<Integer, AppScanStats> mAppScanStats = new HashMap<Integer, AppScanStats>(); @@ -236,7 +239,7 @@ import java.util.UUID; appName = "Unknown App (UID: " + appUid + ")"; } - synchronized (mApps) { + synchronized (mAppsLock) { AppAdvertiseStats appAdvertiseStats = mAppAdvertiseStats.get(id); if (appAdvertiseStats == null) { appAdvertiseStats = new AppAdvertiseStats(appUid, id, appName, this, service); diff --git a/android/app/src/com/android/bluetooth/gatt/GattService.java b/android/app/src/com/android/bluetooth/gatt/GattService.java index 2c0ff668774..c3d30472c71 100644 --- a/android/app/src/com/android/bluetooth/gatt/GattService.java +++ b/android/app/src/com/android/bluetooth/gatt/GattService.java @@ -224,9 +224,9 @@ public class GattService extends ProfileService { /** * List of our registered advertisers. */ - class AdvertiserMap extends ContextMap<IAdvertisingSetCallback, Void> {} + static class AdvertiserMap extends ContextMap<IAdvertisingSetCallback, Void> {} - AdvertiserMap mAdvertiserMap = new AdvertiserMap(); + private AdvertiserMap mAdvertiserMap = new AdvertiserMap(); /** * List of our registered clients. @@ -330,7 +330,7 @@ public class GattService extends ProfileService { mBluetoothAdapterProxy = BluetoothAdapterProxy.getInstance(); mCompanionManager = getSystemService(CompanionDeviceManager.class); mAppOps = getSystemService(AppOpsManager.class); - mAdvertiseManager = new AdvertiseManager(this, mAdapterService); + mAdvertiseManager = new AdvertiseManager(this, mAdapterService, mAdvertiserMap); mAdvertiseManager.start(); mScanManager = new ScanManager(this, mAdapterService, mBluetoothAdapterProxy); -- GitLab