From da9a3e714d76baa8e6e02825a05dd7341be0ec43 Mon Sep 17 00:00:00 2001 From: Marvin W Date: Sat, 12 Sep 2020 21:51:37 +0200 Subject: [PATCH] EN: Support SDK 26+ AdvertisingSet, use scheduled alarms for improved scanning in idle --- .../exposurenotification/AdvertiserService.kt | 245 ++++++++++-------- .../nearby/exposurenotification/DeviceInfo.kt | 2 +- .../exposurenotification/ScannerService.kt | 46 +++- 3 files changed, 168 insertions(+), 125 deletions(-) diff --git a/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/AdvertiserService.kt b/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/AdvertiserService.kt index b1802a1b..052da82c 100644 --- a/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/AdvertiserService.kt +++ b/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/AdvertiserService.kt @@ -6,66 +6,61 @@ package org.microg.gms.nearby.exposurenotification import android.annotation.TargetApi +import android.app.AlarmManager +import android.app.PendingIntent +import android.app.PendingIntent.FLAG_ONE_SHOT +import android.app.PendingIntent.FLAG_UPDATE_CURRENT +import android.app.Service import android.bluetooth.BluetoothAdapter -import android.bluetooth.le.AdvertiseCallback -import android.bluetooth.le.AdvertiseData -import android.bluetooth.le.AdvertiseSettings +import android.bluetooth.le.* import android.bluetooth.le.AdvertiseSettings.* -import android.bluetooth.le.BluetoothLeAdvertiser import android.content.BroadcastReceiver import android.content.Context import android.content.Intent import android.content.IntentFilter +import android.os.* import android.util.Log -import androidx.lifecycle.LifecycleService -import androidx.lifecycle.lifecycleScope -import kotlinx.coroutines.delay import org.microg.gms.common.ForegroundServiceContext import java.io.FileDescriptor import java.io.PrintWriter import java.nio.ByteBuffer import java.util.* -import kotlin.coroutines.resume -import kotlin.coroutines.resumeWithException -import kotlin.coroutines.suspendCoroutine -import kotlin.random.Random @TargetApi(21) -class AdvertiserService : LifecycleService() { +class AdvertiserService : Service() { private val version = VERSION_1_0 - private var looping = false - private var callback: AdvertiseCallback? = null + private var advertising = false + private var wantStartAdvertising = false private val advertiser: BluetoothLeAdvertiser? get() = BluetoothAdapter.getDefaultAdapter()?.bluetoothLeAdvertiser + private val alarmManager: AlarmManager + get() = getSystemService(Context.ALARM_SERVICE) as AlarmManager private lateinit var database: ExposureDatabase + private val callback: AdvertiseCallback = object : AdvertiseCallback() { + override fun onStartSuccess(settingsInEffect: AdvertiseSettings?) { + Log.d(TAG, "Advertising active for ${settingsInEffect?.timeout}ms") + } + + override fun onStartFailure(errorCode: Int) { + Log.w(TAG, "Advertising failed: $errorCode") + stopOrRestartAdvertising() + } + } + + @TargetApi(23) + private var setCallback: AdvertisingSetCallback? = null private val trigger = object : BroadcastReceiver() { override fun onReceive(context: Context?, intent: Intent?) { if (intent?.action == "android.bluetooth.adapter.action.STATE_CHANGED") { when (intent.getIntExtra(BluetoothAdapter.EXTRA_STATE, -1)) { - BluetoothAdapter.STATE_TURNING_OFF, BluetoothAdapter.STATE_OFF -> stopAdvertising() - BluetoothAdapter.STATE_ON -> { - if (looping) { - lifecycleScope.launchWhenStarted { restartAdvertising() } - } else { - loopAdvertising() - } - } + BluetoothAdapter.STATE_TURNING_OFF, BluetoothAdapter.STATE_OFF -> stopOrRestartAdvertising() + BluetoothAdapter.STATE_ON -> startAdvertisingIfNeeded() } } } } - - private suspend fun BluetoothLeAdvertiser.startAdvertising(settings: AdvertiseSettings, advertiseData: AdvertiseData): AdvertiseCallback = suspendCoroutine { - startAdvertising(settings, advertiseData, object : AdvertiseCallback() { - override fun onStartSuccess(settingsInEffect: AdvertiseSettings) { - it.resume(this) - } - - override fun onStartFailure(errorCode: Int) { - it.resumeWithException(RuntimeException("Error code: $errorCode")) - } - }) - } + private val handler = Handler(Looper.getMainLooper()) + private val startLaterRunnable = Runnable { startAdvertisingIfNeeded() } override fun onCreate() { super.onCreate() @@ -76,10 +71,10 @@ class AdvertiserService : LifecycleService() { override fun onStartCommand(intent: Intent?, flags: Int, startId: Int): Int { ForegroundServiceContext.completeForegroundService(this, intent, TAG) super.onStartCommand(intent, flags, startId) - if (ExposurePreferences(this).enabled) { - loopAdvertising() + if (intent?.action == ACTION_RESTART_ADVERTISING && advertising) { + stopOrRestartAdvertising() } else { - stopSelf() + startAdvertisingIfNeeded() } return START_STICKY } @@ -87,87 +82,79 @@ class AdvertiserService : LifecycleService() { override fun onDestroy() { super.onDestroy() unregisterReceiver(trigger) - stopAdvertising() + stopOrRestartAdvertising() database.unref() } - @Synchronized - fun loopAdvertising() { - if (looping) return - looping = true - lifecycleScope.launchWhenStarted { - Log.d(TAG, "Looping advertising") - try { - do { - val aem = when (version) { - VERSION_1_0 -> byteArrayOf( - version, // Version and flags - (currentDeviceInfo.txPowerCorrection + TX_POWER_LOW).toByte(), // TX power - 0x00, // Reserved - 0x00 // Reserved - ) - VERSION_1_1 -> byteArrayOf( - (version + currentDeviceInfo.confidence * 4).toByte(), // Version and flags - (currentDeviceInfo.txPowerCorrection + TX_POWER_LOW).toByte(), // TX power - 0x00, // Reserved - 0x00 // Reserved - ) - else -> return@launchWhenStarted - } - val payload = database.generateCurrentPayload(aem) - val nextSend = (nextKeyMillis + Random.nextInt(-ADVERTISER_OFFSET, ADVERTISER_OFFSET)).coerceIn(0, 180000) - startAdvertising(payload, nextSend.toInt()) - if (callback != null) delay(nextSend) - } while (callback != null) - } catch (e: Exception) { - Log.w(TAG, "Error during advertising loop", e) - } - Log.d(TAG, "No longer advertising") - synchronized(this@AdvertiserService) { - looping = false - } + override fun onBind(intent: Intent?): IBinder? { + return null + } + + fun startAdvertisingIfNeeded() { + if (ExposurePreferences(this).enabled) { + startAdvertising() + } else { + stopSelf() } } - var startTime = System.currentTimeMillis() - var sendingBytes = ByteArray(0) - var sendingNext = 0 - suspend fun startAdvertising(bytes: ByteArray, nextSend: Int) { - startTime = System.currentTimeMillis() - sendingBytes = bytes - sendingNext = nextSend - continueAdvertising(bytes, nextSend) - } + private var lastStartTime = System.currentTimeMillis() + private var sendingBytes = ByteArray(0) - private suspend fun continueAdvertising(bytes: ByteArray, nextSend: Int) { - stopAdvertising() - val data = AdvertiseData.Builder().addServiceUuid(SERVICE_UUID).addServiceData(SERVICE_UUID, bytes).build() - val settings = Builder() - .setTimeout(nextSend) - .setAdvertiseMode(ADVERTISE_MODE_LOW_POWER) - .setTxPowerLevel(ADVERTISE_TX_POWER_MEDIUM) - .setConnectable(false) - .build() - val (uuid, aem) = ByteBuffer.wrap(bytes).let { UUID(it.long, it.long) to it.int } - Log.d(TAG, "RPI: $uuid, Version: 0x${version.toString(16)}, TX Power: ${currentDeviceInfo.txPowerCorrection + TX_POWER_LOW}, AEM: 0x${aem.toLong().let { if (it < 0) 0x100000000L + it else it }.toString(16)}, Timeout: ${nextSend}ms") - callback = advertiser?.startAdvertising(settings, data) - } - - suspend fun restartAdvertising() { - val startTime = startTime - val bytes = sendingBytes - val next = sendingNext - if (next == 0 || bytes.isEmpty()) return - val nextSend = (startTime - System.currentTimeMillis() + next).toInt() - if (nextSend < 5000) return - continueAdvertising(bytes, nextSend) + @Synchronized + fun startAdvertising() { + if (advertising) return + val advertiser = advertiser ?: return + wantStartAdvertising = false + val aemBytes = when (version) { + VERSION_1_0 -> byteArrayOf( + version, // Version and flags + (currentDeviceInfo.txPowerCorrection + TX_POWER_LOW).toByte(), // TX power + 0x00, // Reserved + 0x00 // Reserved + ) + VERSION_1_1 -> byteArrayOf( + (version + currentDeviceInfo.confidence * 4).toByte(), // Version and flags + (currentDeviceInfo.txPowerCorrection + TX_POWER_LOW).toByte(), // TX power + 0x00, // Reserved + 0x00 // Reserved + ) + else -> return + } + var nextSend = nextKeyMillis.coerceAtLeast(10000) + val payload = database.generateCurrentPayload(aemBytes) + val data = AdvertiseData.Builder().addServiceUuid(SERVICE_UUID).addServiceData(SERVICE_UUID, payload).build() + val (uuid, _) = ByteBuffer.wrap(payload).let { UUID(it.long, it.long) to it.int } + Log.i(TAG, "Starting advertiser for RPI $uuid") + if (Build.VERSION.SDK_INT >= 26) { + setCallback = SetCallback() + val params = AdvertisingSetParameters.Builder() + .setInterval(AdvertisingSetParameters.INTERVAL_MEDIUM) + .setLegacyMode(true) + .setTxPowerLevel(AdvertisingSetParameters.TX_POWER_LOW) + .setConnectable(false) + .build() + advertiser.startAdvertisingSet(params, data, null, null, null, setCallback) + } else { + nextSend = nextSend.coerceAtMost(180000) + val settings = Builder() + .setTimeout(nextSend.toInt()) + .setAdvertiseMode(ADVERTISE_MODE_BALANCED) + .setTxPowerLevel(ADVERTISE_TX_POWER_LOW) + .setConnectable(false) + .build() + advertiser.startAdvertising(settings, data, callback) + } + advertising = true + sendingBytes = payload + lastStartTime = System.currentTimeMillis() + scheduleRestartAdvertising(nextSend) } override fun dump(fd: FileDescriptor?, writer: PrintWriter?, args: Array?) { - writer?.println("Looping: $looping") - writer?.println("Active: ${callback != null}") + writer?.println("Advertising: $advertising") try { - val startTime = startTime + val startTime = lastStartTime val bytes = sendingBytes val (uuid, aem) = ByteBuffer.wrap(bytes).let { UUID(it.long, it.long) to it.int } writer?.println(""" @@ -183,15 +170,53 @@ class AdvertiserService : LifecycleService() { } } + private fun scheduleRestartAdvertising(nextSend: Long) { + val intent = Intent(this, AdvertiserService::class.java).apply { action = ACTION_RESTART_ADVERTISING } + val pendingIntent = PendingIntent.getService(this, ACTION_RESTART_ADVERTISING.hashCode(), intent, FLAG_ONE_SHOT and FLAG_UPDATE_CURRENT) + when { + Build.VERSION.SDK_INT >= 23 -> + alarmManager.setExactAndAllowWhileIdle(AlarmManager.ELAPSED_REALTIME_WAKEUP, SystemClock.elapsedRealtime() + nextSend, pendingIntent) + else -> + alarmManager.setExact(AlarmManager.ELAPSED_REALTIME_WAKEUP, SystemClock.elapsedRealtime() + nextSend, pendingIntent) + } + } + @Synchronized - fun stopAdvertising() { - callback?.let { advertiser?.stopAdvertising(it) } - callback = null + fun stopOrRestartAdvertising() { + if (!advertising) return + val (uuid, _) = ByteBuffer.wrap(sendingBytes).let { UUID(it.long, it.long) to it.int } + Log.i(TAG, "Stopping advertiser for RPI $uuid") + advertising = false + if (Build.VERSION.SDK_INT >= 26) { + wantStartAdvertising = true + advertiser?.stopAdvertisingSet(setCallback) + } else { + advertiser?.stopAdvertising(callback) + } + handler.postDelayed(startLaterRunnable, 1000) } companion object { + private const val ACTION_RESTART_ADVERTISING = "org.microg.gms.nearby.exposurenotification.RESTART_ADVERTISING" + fun isNeeded(context: Context): Boolean { return ExposurePreferences(context).enabled } } + + @TargetApi(26) + inner class SetCallback : AdvertisingSetCallback() { + override fun onAdvertisingSetStarted(advertisingSet: AdvertisingSet?, txPower: Int, status: Int) { + Log.d(TAG, "Advertising active, status=$status") + } + + override fun onAdvertisingSetStopped(advertisingSet: AdvertisingSet?) { + Log.d(TAG, "Advertising stopped") + if (wantStartAdvertising) { + startAdvertisingIfNeeded() + } else { + stopOrRestartAdvertising() + } + } + } } diff --git a/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/DeviceInfo.kt b/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/DeviceInfo.kt index 12aaa42d..e16c4c20 100644 --- a/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/DeviceInfo.kt +++ b/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/DeviceInfo.kt @@ -39,7 +39,7 @@ val currentDeviceInfo: DeviceInfo averageCurrentDeviceInfo(Build.MANUFACTURER, Build.MODEL, allDeviceInfos, CONFIDENCE_LOWEST) } } - Log.d(TAG, "Selected $deviceInfo") + Log.i(TAG, "Selected $deviceInfo") knownDeviceInfo = deviceInfo } return deviceInfo diff --git a/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/ScannerService.kt b/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/ScannerService.kt index 8439291c..fdbeed2b 100644 --- a/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/ScannerService.kt +++ b/play-services-nearby-core/src/main/kotlin/org/microg/gms/nearby/exposurenotification/ScannerService.kt @@ -5,7 +5,10 @@ package org.microg.gms.nearby.exposurenotification +import android.annotation.SuppressLint import android.annotation.TargetApi +import android.app.AlarmManager +import android.app.PendingIntent import android.app.Service import android.bluetooth.BluetoothAdapter.* import android.bluetooth.le.* @@ -13,10 +16,7 @@ import android.content.BroadcastReceiver import android.content.Context import android.content.Intent import android.content.IntentFilter -import android.os.Build -import android.os.Handler -import android.os.IBinder -import android.os.Looper +import android.os.* import android.util.Log import org.microg.gms.common.ForegroundServiceContext import java.io.FileDescriptor @@ -36,7 +36,6 @@ class ScannerService : Service() { } override fun onBatchScanResults(results: MutableList) { - Log.d(TAG, "onBatchScanResults: ${results.size}") for (result in results) { onScanResult(result) } @@ -59,10 +58,19 @@ class ScannerService : Service() { } private val handler = Handler(Looper.getMainLooper()) private val stopLaterRunnable = Runnable { stopScan() } - private val startLaterRunnable = Runnable { startScan() } + + // Wake lock for the duration of scan. Otherwise we might fall asleep while scanning + // resulting in potentially very long scan times + private val wakeLock: PowerManager.WakeLock by lazy { + powerManager.newWakeLock(PowerManager.PARTIAL_WAKE_LOCK, ScannerService::class.java.canonicalName).apply { setReferenceCounted(false) } + } private val scanner: BluetoothLeScanner? get() = getDefaultAdapter()?.bluetoothLeScanner + private val alarmManager: AlarmManager + get() = getSystemService(Context.ALARM_SERVICE) as AlarmManager + private val powerManager: PowerManager + get() = getSystemService(Context.POWER_SERVICE) as PowerManager override fun onStartCommand(intent: Intent?, flags: Int, startId: Int): Int { ForegroundServiceContext.completeForegroundService(this, intent, TAG) @@ -104,21 +112,20 @@ class ScannerService : Service() { return null } + @SuppressLint("WakelockTimeout") @Synchronized private fun startScan() { if (scanning) return val scanner = scanner ?: return - Log.d(TAG, "Starting scanner for service $SERVICE_UUID") - handler.removeCallbacks(startLaterRunnable) + Log.i(TAG, "Starting scanner for service $SERVICE_UUID for ${SCANNING_TIME_MS}ms") seenAdvertisements = 0 + wakeLock.acquire() scanner.startScan( listOf(ScanFilter.Builder() .setServiceUuid(SERVICE_UUID) .setServiceData(SERVICE_UUID, byteArrayOf(0), byteArrayOf(0)) .build()), - ScanSettings.Builder() - .let { if (Build.VERSION.SDK_INT >= 23) it.setMatchMode(ScanSettings.MATCH_MODE_STICKY) else it } - .build(), + ScanSettings.Builder().build(), callback ) scanning = true @@ -129,12 +136,24 @@ class ScannerService : Service() { @Synchronized private fun stopScan() { if (!scanning) return - Log.d(TAG, "Stopping scanner for service $SERVICE_UUID") + Log.i(TAG, "Stopping scanner for service $SERVICE_UUID, had seen $seenAdvertisements advertisements") handler.removeCallbacks(stopLaterRunnable) scanning = false scanner?.stopScan(callback) if (ExposurePreferences(this).enabled) { - handler.postDelayed(startLaterRunnable, ((lastStartTime + SCANNING_INTERVAL_MS) - System.currentTimeMillis()).coerceIn(0, SCANNING_INTERVAL_MS)) + scheduleStartScan(((lastStartTime + SCANNING_INTERVAL_MS) - System.currentTimeMillis()).coerceIn(0, SCANNING_INTERVAL_MS)) + } + wakeLock.release() + } + + private fun scheduleStartScan(nextScan: Long) { + val intent = Intent(this, ScannerService::class.java) + val pendingIntent = PendingIntent.getService(this, ScannerService::class.java.hashCode(), intent, PendingIntent.FLAG_ONE_SHOT and PendingIntent.FLAG_UPDATE_CURRENT) + if (Build.VERSION.SDK_INT >= 23) { + // Note: there is no setWindowAndAllowWhileIdle() + alarmManager.setExactAndAllowWhileIdle(AlarmManager.ELAPSED_REALTIME_WAKEUP, SystemClock.elapsedRealtime() + nextScan, pendingIntent) + } else { + alarmManager.setWindow(AlarmManager.ELAPSED_REALTIME_WAKEUP, SystemClock.elapsedRealtime() + nextScan - SCANNING_TIME_MS / 2, SCANNING_TIME_MS, pendingIntent) } } @@ -142,7 +161,6 @@ class ScannerService : Service() { writer?.println("Scanning now: $scanning") writer?.println("Last scan start: ${Date(lastStartTime)}") if (Build.VERSION.SDK_INT >= 29) { - writer?.println("Scan start pending: ${handler.hasCallbacks(startLaterRunnable)}") writer?.println("Scan stop pending: ${handler.hasCallbacks(stopLaterRunnable)}") } writer?.println("Seen advertisements since last scan start: $seenAdvertisements")