TySS-Dev/capod
1
0
Fork 0
mirror of https://github.com/d4rken-org/capod.git synced 2026-09-14 18:26:11 -04:00
Code Issues Packages Projects Releases Wiki Activity

fix(logging): Demote noisy BLE logs and redact summaries

Browse Source
This commit is contained in:
darken
2026-04-14 11:28:41 +02:00
committed by Matthias Urhahn
parent 71ba531025
commit e6e66c3831
10 changed files with 61 additions and 47 deletions
Download Patch File Download Diff File Expand all files Collapse all files
app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultForwarder.kt
+3 -3
View File
@@ -22,12 +22,12 @@ class BleScanResultForwarder @Inject constructor() {
val results: Flow<Collection<ScanResult>> = forwarder
fun forward(scanResults: Collection<ScanResult>) {
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")
}
}
}
app/src/main/java/eu/darken/capod/common/bluetooth/BleScanResultReceiver.kt
+2 -2
View File
@@ -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<ScanResult>(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!" }
app/src/main/java/eu/darken/capod/common/bluetooth/BleScanner.kt
+12 -7
View File
@@ -44,7 +44,9 @@ class BleScanner @Inject constructor(
disableOffloadBatching: Boolean = false,
disableDirectScanCallback: Boolean = false,
): Flow<Collection<BleScanResult>> = 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)
}
app/src/main/java/eu/darken/capod/common/bluetooth/BleScannerExtensions.kt
+2 -2
View File
@@ -10,7 +10,7 @@ suspend fun Collection<BleScanResult>.onlyNewAndUnique(): List<BleScanResult> =
// 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
}
}
app/src/main/java/eu/darken/capod/main/core/PermissionTool.kt
+5 -2
View File
@@ -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<Set<Permission>> = missingPermissions
.map { perms -> perms.filter { it.isScanBlocking }.toSet() }
@@ -59,4 +62,4 @@ class PermissionTool @Inject constructor(
companion object {
private val TAG = logTag("PermissionTool")
}
}
}
app/src/main/java/eu/darken/capod/main/ui/widget/WidgetManager.kt
+2 -1
View File
@@ -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)
}
app/src/main/java/eu/darken/capod/pods/core/apple/ble/AppleFactory.kt
+12 -8
View File
@@ -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")
}
}
}
app/src/main/java/eu/darken/capod/pods/core/apple/ble/BlePodSnapshot.kt
-3
View File
@@ -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
}
app/src/main/java/eu/darken/capod/pods/core/apple/ble/PodFactory.kt
+6 -9
View File
@@ -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")
}
}
}
app/src/main/java/eu/darken/capod/pods/core/apple/ble/history/PodHistoryRepo.kt
+17 -10
View File
@@ -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")
}
}
}