diff --git a/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultForwarder.kt b/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultForwarder.kt index aeb9fd97..28fa2fae 100644 --- a/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultForwarder.kt +++ b/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultForwarder.kt @@ -22,12 +22,12 @@ class BleScanResultForwarder @Inject constructor() { val results: Flow> = forwarder fun forward(scanResults: Collection) { - log(TAG, VERBOSE) { "forward($scanResults)" } + log(TAG, VERBOSE) { "forward(${scanResults.logSummary()})" } val success = forwarder.tryEmit(scanResults) - if (!success) log(TAG, WARN) { "Failed to forward (overflow?) $scanResults" } + if (!success) log(TAG, WARN) { "Failed to forward (overflow?) ${scanResults.logSummary()}" } } companion object { private val TAG = logTag("Bluetooth", "BleScanner", "Forwarder") } -} \ No newline at end of file +} diff --git a/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultReceiver.kt b/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultReceiver.kt index 897d2174..4c0f6cfe 100644 --- a/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultReceiver.kt +++ b/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultReceiver.kt @@ -22,7 +22,7 @@ class BleScanResultReceiver : BroadcastReceiver() { @Inject lateinit var scanResultForwarder: BleScanResultForwarder override fun onReceive(context: Context, intent: Intent) { - log(TAG, VERBOSE) { "onReceive($context, $intent)" } + log(TAG, VERBOSE) { "onReceive(action=${intent.action})" } if (intent.action != ACTION) { log(TAG, WARN) { "Unknown action: ${intent.action}" } return @@ -43,7 +43,7 @@ class BleScanResultReceiver : BroadcastReceiver() { log(TAG, VERBOSE) { "callbackType=$callbackType" } val scanResults = intent.getParcelableArrayListExtra(BluetoothLeScanner.EXTRA_LIST_SCAN_RESULT) - log(TAG, VERBOSE) { "scanResults=$scanResults" } + log(TAG, VERBOSE) { "scanResults=${scanResults?.logSummary() ?: "count=0"}" } if (scanResults == null) { log(TAG) { "Scan results were empty!" } diff --git a/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanner.kt b/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanner.kt index a08cdf27..e13d4f5e 100644 --- a/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanner.kt +++ b/app/src/main/java/eu/darken/capod/common/bluetooth/BleScanner.kt @@ -44,7 +44,9 @@ class BleScanner @Inject constructor( disableOffloadBatching: Boolean = false, disableDirectScanCallback: Boolean = false, ): Flow> = callbackFlow { - log(TAG) { "scan(filters=$filters, scannerMode=$scannerMode)" } + log(TAG) { + "scan(filterCount=${filters.size}, scannerMode=$scannerMode, directCallback=${!disableDirectScanCallback})" + } val adapter = bluetoothManager.adapter ?: throw IllegalStateException("Bluetooth adapter unavailable") @@ -70,7 +72,7 @@ class BleScanner @Inject constructor( filters.isEmpty() -> true else -> filters.any { it.matches(result) } } - if (!passed) log(TAG, VERBOSE) { "Manually filtered $result" } + if (!passed) log(TAG, VERBOSE) { "Manually filtered ${result.logSummary()}" } passed } .map { BleScanResult.fromScanResult(it, timeSource) } @@ -82,7 +84,7 @@ class BleScanner @Inject constructor( log(TAG, VERBOSE) { val delay = timeSource.currentTimeMillis() - lastScanAt lastScanAt = timeSource.currentTimeMillis() - "onScanResult(delay=${delay}ms, callbackType=$callbackType, result=$result)" + "onScanResult(delay=${delay}ms, callbackType=$callbackType, ${result.logSummary()})" } trySend(filterResults(setOf(result))) @@ -92,7 +94,7 @@ class BleScanner @Inject constructor( log(TAG, VERBOSE) { val delay = timeSource.currentTimeMillis() - lastScanAt lastScanAt = timeSource.currentTimeMillis() - "onBatchScanResults(delay=${delay}ms, results=$results)" + "onBatchScanResults(delay=${delay}ms, ${results.logSummary()})" } trySend(filterResults(results)) @@ -115,7 +117,6 @@ class BleScanner @Inject constructor( launch { log(TAG) { "Flush job launched" } while (isActive) { - log(TAG, VERBOSE) { "Flushing scan results." } // Can undercut the minimum setReportDelay(), e.g. 5000ms on a Pixel5@12 adapter.bluetoothLeScanner.flushPendingScanResults(callback) when (scannerMode) { @@ -168,10 +169,14 @@ class BleScanner @Inject constructor( if (disableDirectScanCallback) { val callbackIntent = createStartIntent() - log(TAG) { "Intent callback: startScan(filters=$filters, settings=$scanSettings, callbackIntent=$callbackIntent)" } + log(TAG) { + "startScan(mode=$scannerMode, filterCount=${filterList.size}, batching=$useOffloadedBatching, filtering=$useOffloadedFiltering, callback=intent)" + } scanner.startScan(filterList, scanSettings, callbackIntent) } else { - log(TAG) { "Direct callback: startScan(filters=$filters, settings=$scanSettings, callback=$callback)" } + log(TAG) { + "startScan(mode=$scannerMode, filterCount=${filterList.size}, batching=$useOffloadedBatching, filtering=$useOffloadedFiltering, callback=direct)" + } scanner.startScan(filterList, scanSettings, callback) } diff --git a/app/src/main/java/eu/darken/capod/common/bluetooth/BleScannerExtensions.kt b/app/src/main/java/eu/darken/capod/common/bluetooth/BleScannerExtensions.kt index 378375d0..2665a83b 100644 --- a/app/src/main/java/eu/darken/capod/common/bluetooth/BleScannerExtensions.kt +++ b/app/src/main/java/eu/darken/capod/common/bluetooth/BleScannerExtensions.kt @@ -10,7 +10,7 @@ suspend fun Collection.onlyNewAndUnique(): List = // For each address we only want the newest result, upstream may batch data val newest = sameAdrDevs.maxByOrNull { it.generatedAtNanos }!! sameAdrDevs.minus(newest).let { - if (it.isNotEmpty()) log( VERBOSE) { "Discarding stale results: $it" } + if (it.isNotEmpty()) log(VERBOSE) { "Discarding stale results: ${it.logSummary()}" } } newest - } \ No newline at end of file + } diff --git a/app/src/main/java/eu/darken/capod/main/core/PermissionTool.kt b/app/src/main/java/eu/darken/capod/main/core/PermissionTool.kt index 4e54186d..442f704d 100644 --- a/app/src/main/java/eu/darken/capod/main/core/PermissionTool.kt +++ b/app/src/main/java/eu/darken/capod/main/core/PermissionTool.kt @@ -51,7 +51,10 @@ class PermissionTool @Inject constructor( .filter { it.isRequired(context) } .toSet() } - .onEach { log(TAG) { "Missing permission: $it" } } + .distinctUntilChanged() + .onEach { missing -> + if (missing.isNotEmpty()) log(TAG) { "Missing permissions: $missing" } + } val missingScanPermissions: Flow> = missingPermissions .map { perms -> perms.filter { it.isScanBlocking }.toSet() } @@ -59,4 +62,4 @@ class PermissionTool @Inject constructor( companion object { private val TAG = logTag("PermissionTool") } -} \ No newline at end of file +} diff --git a/app/src/main/java/eu/darken/capod/main/ui/widget/WidgetManager.kt b/app/src/main/java/eu/darken/capod/main/ui/widget/WidgetManager.kt index f02cda53..ad10a6b0 100644 --- a/app/src/main/java/eu/darken/capod/main/ui/widget/WidgetManager.kt +++ b/app/src/main/java/eu/darken/capod/main/ui/widget/WidgetManager.kt @@ -3,6 +3,7 @@ package eu.darken.capod.main.ui.widget import android.content.Context import androidx.glance.appwidget.updateAll import dagger.hilt.android.qualifiers.ApplicationContext +import eu.darken.capod.common.debug.logging.Logging.Priority.VERBOSE import eu.darken.capod.common.debug.logging.log import eu.darken.capod.common.debug.logging.logTag import javax.inject.Inject @@ -15,7 +16,7 @@ class WidgetManager @Inject constructor( ) { suspend fun refreshWidgets() { - log(TAG) { "refreshWidgets()" } + log(TAG, VERBOSE) { "refreshWidgets()" } BatteryGlanceWidget().updateAll(context) } diff --git a/app/src/main/java/eu/darken/capod/pods/core/apple/ble/AppleFactory.kt b/app/src/main/java/eu/darken/capod/pods/core/apple/ble/AppleFactory.kt index ac1b8ee6..fc3b8945 100644 --- a/app/src/main/java/eu/darken/capod/pods/core/apple/ble/AppleFactory.kt +++ b/app/src/main/java/eu/darken/capod/pods/core/apple/ble/AppleFactory.kt @@ -1,9 +1,9 @@ package eu.darken.capod.pods.core.apple.ble import eu.darken.capod.common.bluetooth.BleScanResult +import eu.darken.capod.common.bluetooth.logSummary import eu.darken.capod.common.debug.logging.Logging.Priority.VERBOSE -import eu.darken.capod.common.debug.logging.Logging.Priority.WARN -import eu.darken.capod.common.debug.logging.asLog +import eu.darken.capod.common.debug.logging.Logging.Priority.DEBUG import eu.darken.capod.common.debug.logging.log import eu.darken.capod.common.debug.logging.logTag import eu.darken.capod.pods.core.apple.ble.devices.ApplePods @@ -40,21 +40,23 @@ class AppleFactory @Inject constructor( val messages = try { continuityProtocolDecoder.decode(scanResult) } catch (e: Exception) { - log(TAG, WARN) { "Data wasn't continuity protocol conform:\n${e.asLog()}" } + log(TAG, VERBOSE) { "Not a continuity payload: ${scanResult.logSummary()} (${e.javaClass.simpleName})" } return null } if (messages.isEmpty()) { - log(TAG, WARN) { "Data contained no continuity messages: $scanResult" } + log(TAG, VERBOSE) { "No continuity messages in ${scanResult.logSummary()}" } return null } if (messages.size > 1) { - log(TAG, WARN) { "Decoded multiple continuity messages, picking first: $messages" } + log(TAG, DEBUG) { + "Decoded ${messages.size} continuity messages, picking first for ${scanResult.logSummary()}" + } } val proximityMessage = proximityPairingDecoder.decode(messages.first()) if (proximityMessage == null) { - log(TAG) { "Not a proximity pairing message: $messages" } + log(TAG, VERBOSE) { "Not a proximity pairing message for ${scanResult.logSummary()}" } return null } @@ -71,7 +73,9 @@ class AppleFactory @Inject constructor( } val isIrkMatch = profile != null - if (isIrkMatch) log(TAG, VERBOSE) { "IRK match for $scanResult -> $profile" } + if (isIrkMatch) { + log(TAG, VERBOSE) { "IRK match for ${scanResult.logSummary()} -> ${profile?.logSummary()}" } + } var payload = ProximityPayload( public = ProximityPayload.Public( @@ -127,4 +131,4 @@ class AppleFactory @Inject constructor( companion object { private val TAG = logTag("Pod", "Apple", "Factory") } -} \ No newline at end of file +} diff --git a/app/src/main/java/eu/darken/capod/pods/core/apple/ble/BlePodSnapshot.kt b/app/src/main/java/eu/darken/capod/pods/core/apple/ble/BlePodSnapshot.kt index 0be97c64..953caab7 100644 --- a/app/src/main/java/eu/darken/capod/pods/core/apple/ble/BlePodSnapshot.kt +++ b/app/src/main/java/eu/darken/capod/pods/core/apple/ble/BlePodSnapshot.kt @@ -5,8 +5,6 @@ import androidx.annotation.DrawableRes import eu.darken.capod.common.SystemTimeSource import eu.darken.capod.common.bluetooth.BleScanResult import eu.darken.capod.common.bluetooth.BluetoothAddress -import eu.darken.capod.common.debug.logging.Logging.Priority.VERBOSE -import eu.darken.capod.common.debug.logging.log import eu.darken.capod.pods.core.apple.PodModel import eu.darken.capod.profiles.core.DeviceProfile import java.time.Duration @@ -55,7 +53,6 @@ interface BlePodSnapshot { val sqRssi = ((rssi + 100) / 70f).coerceIn(0f, 1f) val sqReliability = max(BASE_CONFIDENCE, reliability) val sqAge = (Duration.between(seenFirstAt, SystemTimeSource.now()).toMinutes().coerceAtMost(60) / 60f) * 0.25f - log(VERBOSE) { "Signal Quality ($address): rssi=$sqRssi, reliability=$reliability, age=$sqAge" } return (sqRssi + sqReliability + sqAge) / 2f } diff --git a/app/src/main/java/eu/darken/capod/pods/core/apple/ble/PodFactory.kt b/app/src/main/java/eu/darken/capod/pods/core/apple/ble/PodFactory.kt index d73c8407..5f8d2bec 100644 --- a/app/src/main/java/eu/darken/capod/pods/core/apple/ble/PodFactory.kt +++ b/app/src/main/java/eu/darken/capod/pods/core/apple/ble/PodFactory.kt @@ -2,7 +2,8 @@ package eu.darken.capod.pods.core.apple.ble import dagger.Reusable import eu.darken.capod.common.bluetooth.BleScanResult -import eu.darken.capod.common.debug.logging.Logging.Priority.INFO +import eu.darken.capod.common.bluetooth.logSummary +import eu.darken.capod.common.debug.logging.Logging.Priority.DEBUG import eu.darken.capod.common.debug.logging.Logging.Priority.VERBOSE import eu.darken.capod.common.debug.logging.log import eu.darken.capod.common.debug.logging.logTag @@ -16,9 +17,7 @@ class PodFactory @Inject constructor( ) { suspend fun createPod(scanResult: BleScanResult): Result? { - log(TAG, VERBOSE) { "Trying to create Pod for $scanResult" } - - log(TAG, INFO) { "Decoding $scanResult" } + log(TAG, VERBOSE) { "Decoding ${scanResult.logSummary()}" } var device = appleFactory.create(scanResult) @@ -27,10 +26,8 @@ class PodFactory @Inject constructor( device = unknownFactory.create(scanResult) } - log(TAG, INFO) { "Pod created: $device" } - return device?.let { - Result(scanResult = scanResult, device = it) - } + log(TAG, DEBUG) { "Pod created: ${device.logSummary()}" } + return Result(scanResult = scanResult, device = device) } data class Result( @@ -41,4 +38,4 @@ class PodFactory @Inject constructor( companion object { private val TAG = logTag("Pod", "Factory") } -} \ No newline at end of file +} diff --git a/app/src/main/java/eu/darken/capod/pods/core/apple/ble/history/PodHistoryRepo.kt b/app/src/main/java/eu/darken/capod/pods/core/apple/ble/history/PodHistoryRepo.kt index c9549ec1..be90a939 100644 --- a/app/src/main/java/eu/darken/capod/pods/core/apple/ble/history/PodHistoryRepo.kt +++ b/app/src/main/java/eu/darken/capod/pods/core/apple/ble/history/PodHistoryRepo.kt @@ -8,6 +8,7 @@ import eu.darken.capod.common.debug.logging.logTag import eu.darken.capod.common.lowerNibble import eu.darken.capod.common.upperNibble import eu.darken.capod.pods.core.apple.ble.BlePodSnapshot +import eu.darken.capod.pods.core.apple.ble.logSummary import eu.darken.capod.pods.core.apple.ble.devices.HasCase import eu.darken.capod.pods.core.apple.PodModel import eu.darken.capod.pods.core.apple.ble.devices.ApplePods @@ -81,17 +82,21 @@ class PodHistoryRepo @Inject constructor( emptySet() } - log(TAG, DEBUG) { "search2: Case ignored matches(${caseIgnored.size}): $caseIgnored" } + if (caseIgnored.isNotEmpty()) { + log(TAG, VERBOSE) { + "search2: caseIgnoredMatches=${caseIgnored.joinToString { it.logSummary() }}" + } + } return when (caseIgnored.size) { 0 -> basicResult 1 -> caseIgnored.single() else -> { - log(TAG) { "search2: More than one result when ignoring case markers." } + log(TAG, WARN) { "search2: More than one result when ignoring case markers." } val oldest = caseIgnored.maxByOrNull { it.history.size } ?: return null caseIgnored.minus(oldest).forEach { - log(TAG) { "search2: Removing outlier: $it" } + log(TAG, WARN) { "search2: Removing outlier ${it.logSummary()}" } knownDevices.remove(it.id) } @@ -108,7 +113,7 @@ class PodHistoryRepo @Inject constructor( knownDevices.values.toList() .filter { it.isOlderThan(Duration.ofSeconds(30)) } .forEach { knownDevice -> - log(TAG, VERBOSE) { "search1: Removing stale known device: $knownDevice" } + log(TAG, VERBOSE) { "search1: Removing stale ${knownDevice.logSummary()}" } knownDevices.remove(knownDevice.id) } @@ -120,7 +125,7 @@ class PodHistoryRepo @Inject constructor( var recognizedDevice: KnownDevice? = knownDevices.values .firstOrNull { it.lastAddress == scanResult.address } - ?.also { log(TAG, VERBOSE) { "search1: Recovered previous ID via address: $it" } } + ?.also { log(TAG, VERBOSE) { "search1: Recovered via address: ${it.logSummary()}" } } if (recognizedDevice == null) { val profile = profilesRepo.currentProfiles() @@ -131,7 +136,7 @@ class PodHistoryRepo @Inject constructor( if (profile != null) { recognizedDevice = knownDevices.values .firstOrNull { rpaChecker.verify(it.lastAddress, profile.identityKey!!) } - .also { log(TAG, VERBOSE) { "search1: Recovered previous ID via IRK: $it" } } + .also { log(TAG, VERBOSE) { "search1: Recovered via IRK: ${it?.logSummary()}" } } } } @@ -139,10 +144,12 @@ class PodHistoryRepo @Inject constructor( val currentMarkers = payload.getFuzzyIdentifier() recognizedDevice = knownDevices.values .firstOrNull { it.lastPayload.getFuzzyIdentifier() == currentMarkers } - ?.also { log(TAG) { "search1: Close match based on similarity: $currentMarkers" } } + ?.also { log(TAG, DEBUG) { "search1: Similarity match for device=${current.model}" } } } - if (recognizedDevice == null) log(TAG, WARN) { "search1: Didn't recognize: $current" } + if (recognizedDevice == null) { + log(TAG, DEBUG) { "search1: No history match for ${current.logSummary()}" } + } return recognizedDevice } @@ -163,7 +170,7 @@ class PodHistoryRepo @Inject constructor( lastCaseBattery = history.determineLatestCaseBattery() ?: existing.lastCaseBattery ) } else { - log(TAG) { "Creating new history for $device" } + log(TAG, DEBUG) { "Creating new history for ${device.logSummary()}" } val history = listOf(device) KnownDevice( id = device.identifier, @@ -178,4 +185,4 @@ class PodHistoryRepo @Inject constructor( companion object { private val TAG = logTag("Pod", "Apple", "Factory", "History") } -} \ No newline at end of file +}