diff --git a/.gitignore b/.gitignore index cf5dfae..f181cfd 100644 --- a/.gitignore +++ b/.gitignore @@ -10,3 +10,4 @@ /app/build/ /app/release/ /graphify-out/ +/.local-notes/ diff --git a/README.md b/README.md index 6903877..9573678 100644 --- a/README.md +++ b/README.md @@ -72,6 +72,17 @@ trainer for power, speed and cadence — so recording the *corrected* power matt > Note: Karoo extensions auto-start, so the app is always loaded on the Karoo — the **App active** switch > is how you make sure it isn't consuming anything when you're not using it. +### If the Karoo switches itself off mid-session + +The Karoo powers **itself** off about ten minutes after its screen goes to sleep when no ride is being +recorded — whatever the battery level, and whatever any app is doing. It is the Karoo's own idle +behaviour, not the bridge crashing: the bridge is simply switched off with the rest of the device. + +If you record the ride on the Karoo, this never happens. If you'd rather not record — you use the Karoo +only as the bridge and something else does the recording — turn on **Keep the Karoo awake** in Config. +It briefly wakes the screen every five minutes, which is enough to stop the countdown. That costs +battery (the screen is the biggest consumer on the device), so it is off by default. + --- ## Using it on a phone @@ -122,7 +133,15 @@ Open **Configuración** from the Monitor: because Android has no per-advertisement name — and then anything else the device advertises carries that name too, until it is restored on stop. - **Options** — save diagnostic log (CSV), simulation mode (a fake trainer for testing with no hardware), - ANT+ output + its device id. + ANT+ output + its device id, and the two anti-shutdown switches below. +- **Keep the Karoo awake** (off by default) — stops the Karoo powering itself off while the bridge is + running with no ride recorded; see *If the Karoo switches itself off mid-session* above. It wakes the + screen every five minutes, so it uses noticeably more battery. It stops on its own once there has been + no trainer for a while, so a session you walked away from still lets the device sleep, and it does + nothing while a ride is recording (the Karoo doesn't switch off then anyway). +- **Keep THIS screen on** (off by default) — holds the screen awake **while the Monitor screen is open**, + which also prevents the shutdown. It stops applying the moment you switch to another screen or app, + which is why the switch above exists. --- diff --git a/app/build.gradle.kts b/app/build.gradle.kts index 99e26ab..959769d 100644 --- a/app/build.gradle.kts +++ b/app/build.gradle.kts @@ -11,8 +11,8 @@ android { applicationId = "com.enderthor.trainerbridgeble" minSdk = 26 targetSdk = 34 - versionCode = 20260722 - versionName = "0.9.2" + versionCode = 202609011 + versionName = "0.9.3" } buildTypes { diff --git a/app/manifest.json b/app/manifest.json index e374c4e..ebabd75 100644 --- a/app/manifest.json +++ b/app/manifest.json @@ -3,10 +3,10 @@ "packageName": "com.enderthor.trainerbridgeble", "latestApkUrl": "https://github.com/lockevod/TrainerBridgeBLE/releases/latest/download/trainerbridge.apk", "iconUrl": "https://github.com/lockevod/TrainerBridgeBLE/releases/latest/download/trainerbridge.png", - "latestVersion": "0.9.1", - "latestVersionCode": 20260721, + "latestVersion": "0.9.3", + "latestVersionCode": 202609011, "developer": "Enderthor", "description": "Bridges your indoor trainer to your apps (Bestcycling/Garmin/Karoo), correcting the reported power on the fly and inverting the ERG target, and re-exposes it as a virtual power/cadence/speed sensor to the Karoo.", - "releaseNotes": "Config changes (simulation, pairing, ANT, advertised name) now apply on save, which can briefly drop connected apps \u2014 avoid saving mid-ride. Scan lists only trainers and power meters (retrying unfiltered if that finds nothing) and offers the trainer already in use. With nothing paired the bridge now connects to the first FTMS trainer it finds, so pair yours if another may be in range. Simulation reports the same capabilities as the real trainer. The bridge only advertises while a trainer is connected.", + "releaseNotes": "Improvements.Config changes (simulation, pairing, ANT, advertised name) now apply on save, which can briefly drop connected apps \u2014 avoid saving mid-ride. Scan lists only trainers and power meters (retrying unfiltered if that finds nothing) and offers the trainer already in use. With nothing paired the bridge now connects to the first FTMS trainer it finds, so pair yours if another may be in range. Simulation reports the same capabilities as the real trainer. The bridge only advertises while a trainer is connected.", "tags": ["health","performance"] } diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/BridgeService.kt b/app/src/main/java/com/enderthor/trainerbridgeble/BridgeService.kt index 208fccb..e75f456 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/BridgeService.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/BridgeService.kt @@ -42,7 +42,7 @@ class BridgeService : Service() { @Volatile private var simSource: SimSource? = null // read from GATT binder / server callback @Volatile private var mirror: MirrorServer? = null // threads, so the reference itself must be @Volatile private var antTx: AntFecTx? = null // safely published - private var wakeLock: PowerManager.WakeLock? = null + @Volatile private var wakeLock: PowerManager.WakeLock? = null private val handler = android.os.Handler(android.os.Looper.getMainLooper()) private val lastValues = java.util.concurrent.ConcurrentHashMap() // every value seen, for a late mirror @@ -59,8 +59,10 @@ class BridgeService : Service() { @Volatile var lastSpeedKmh: Double? = null; private set @Volatile var lastCadence: Int? = null; private set @Volatile var lastControl: String? = null; private set - @Volatile var lastSampleMs: Long = 0L; private set // wall-clock of the last trainer sample, for UI staleness - @Volatile var lastPowerMs: Long = 0L; private set // ...and of the last packet that actually CARRIED power + // elapsedRealtime, NOT wall-clock, for both — the reason CorrectedFeed already documents: the Karoo + // re-syncs its clock mid-ride, and a jump either blanks live data or hides a real dropout. + @Volatile var lastSampleMs: Long = 0L; private set // last trainer sample, for UI staleness + @Volatile var lastPowerMs: Long = 0L; private set // ...and the last packet that actually CARRIED power // FTMS says Instantaneous Speed is 0.01 km/h. Some trainers (the Zycle among them) report 0.1 km/h, // which silently makes speed AND the recorded distance ten times too small. Rather than hardcode either, @@ -87,10 +89,26 @@ class BridgeService : Service() { /** Power specifically — a packet can arrive without the power field, and a sticky last value must not be * reported as live to ANT, the Karoo recording, or the tiles. A short grace covers one dropped frame. */ - val powerFresh: Boolean get() = lastPowerMs != 0L && System.currentTimeMillis() - lastPowerMs <= POWER_STALE_MS + val powerFresh: Boolean get() = lastPowerMs != 0L && android.os.SystemClock.elapsedRealtime() - lastPowerMs <= POWER_STALE_MS private fun freshPowerOrNull(): Int? = if (powerFresh) lastCorrectedW else null @Volatile private var lastResistance: Int? = null @Volatile private var sawIndoorBikeData = false // NOT `lastRawW == null`: that is set by the fallback itself + private val pendingErgBias = ErgBiasPersistence(ERG_BIAS_PERSIST_MS, ErgBias::onPower) + /** Owns one receive source at a time. Callback validation and mutation share this monitor with source + * replacement, so teardown cannot overtake a callback that already passed its ownership check. */ + private val receiveOwner = IdentityOwner() + /** Owns one emit instance. MirrorServer.stop() is not a callback barrier, and the toZycle lambda reads + * `client` dynamically — so an app's control write that entered the OLD mirror could change resistance + * or the ERG target on the REPLACEMENT trainer. Validation, the ErgBias/lastControl mutations and the + * capture of the target source happen under this; the write itself is dispatched outside it, because + * writeCharacteristic is a Binder call into the Bluetooth process and stopEmit() waits on this monitor + * from the main thread. */ + private val emitOwner = IdentityOwner() + private var receiveGeneration = 0L + private var ftmsReleaseGeneration: Long? = null + /** How many callbacks the generation guard rejected. Zero all ride means the races the guard exists for + * never happened; a climbing number is itself the finding. Reported by the periodic snapshot. */ + private val staleCallbacks = java.util.concurrent.atomic.AtomicInteger(0) @Volatile private var antEnabled = false @Volatile var antOk = false; private set @Volatile var antStatus: String = ""; private set @@ -118,27 +136,180 @@ class BridgeService : Service() { fun buttonDown() = nudgeResistance(-5) private fun nudgeResistance(delta: Int) { val sim = simSource - if (sim != null) { if (delta > 0) sim.buttonUp() else sim.buttonDown() } + if (sim != null) { + if (delta > 0) sim.buttonUp() else sim.buttonDown() + listener?.invoke() + } else { val target = ((lastResistance ?: 0) + delta).coerceIn(0, 200) // 0..200 per the Zycle's 0x2AD6 range - // ponytail: 0x04+level% Set Target Resistance, no Request Control first — shares the FTMS control point with the app - // Deliberately NOT routed through the mirror, so it arms no servo-step budget: this button is the - // rider, exactly like the bike's own, and the level move it causes SHOULD reach the app. - // optimistic, and only if the write was at least QUEUED (no link / unknown char → don't move the - // tile). A stack refusal after queueing still shows briefly; the trainer's own IBD corrects it. - if (client?.write(com.enderthor.trainerbridgeble.ble.GattUuids.FTMS_CONTROL_POINT, byteArrayOf(0x04, target.toByte()), true) == true) { - lastResistance = target - lastControl = getString(R.string.control_resistance_target, target) - FileLog.event("UI button → resistance target=$target") - } else FileLog.event("UI button → resistance target=$target NOT DISPATCHED") + val bytes = encodeTargetResistance(target) + val localMirror = mirror + val procedure = localMirror?.admitLocalControl(0x04, bytes) + if (localMirror != null && procedure == null) { + lastControl = getString(R.string.status_control_busy) + FileLog.event("UI button → resistance target=$target BLOCKED — FTMS control busy") + listener?.invoke() + return + } + val source = client + if (source == null) { + procedure?.let { localMirror.localControlTransportFailed(it) } + FileLog.event("UI button → resistance target=$target FAILED") + listener?.invoke() + } else source.write( + com.enderthor.trainerbridgeble.ble.GattUuids.FTMS_CONTROL_POINT, + bytes, + true, + ) { success -> + // Arm/close the procedure HERE, on the write callback, not inside the UI post below: + // that post is a second main-loop hop, and an arm that lands after a newer procedure was + // admitted used to strip the newer one of its deadline. + if (success) procedure?.let { localMirror.localControlDispatched(it) } + else procedure?.let { localMirror.localControlTransportFailed(it) } + handler.post { + if (client !== source) return@post + if (success) { + // Transport only. With the mirror up the trainer's FTMS Response Code decides + // acceptance, and onControlAccepted commits it — including telling ErgBias to + // retire any armed ERG target. The response clock starts now, not at admission. + lastResistance = target + if (procedure == null) { + // No mirror: nothing will ever correlate a response, so the write is all we + // have. A trainer that rejects the procedure is indistinguishable from one + // that accepts it on this path. + ErgBias.onControl(bytes, android.os.SystemClock.elapsedRealtime()) + lastControl = getString(R.string.control_resistance_target, target) + } + FileLog.event("UI button → resistance target=$target sent" + + if (procedure != null) " (awaiting trainer verdict #${procedure.id})" else "") + } else FileLog.event("UI button → resistance target=$target FAILED") + listener?.invoke() + } + } } - listener?.invoke() } /** The BLE stack does not survive a Bluetooth off/on (or a crash of com.android.bluetooth): the GATT * server and the advertising set die with it, and nothing reopens them — the mirror goes silently mute * for the rest of the ride. The central half recovers on its own (its scan retries), so only the emit * half is cycled here. */ + // ── Karoo idle-shutdown keep-alive ────────────────────────────────────────────────────────────── + /** `persist.hx.idle_shutdown_delay` is 600000 ms on this firmware. Poke at 5 min, not 8: a single + * missed tick (Karoo system briefly unbound, a late handler) would otherwise eat the whole margin + * and the device powers off anyway. Hard-coded because the property is not readable from an app. */ + private val KEEP_AWAKE_MS = 5 * 60_000L + /** A dispatch that did not reach the host retries in seconds, not at the next 5-minute slot. */ + private val KEEP_AWAKE_RETRY_MS = 20_000L + private var karooSystem: io.hammerhead.karooext.KarooSystemService? = null + /** Recording (or paused) already prevents the idle shutdown, so poking then is pure cost — and it + * relights a display the rider deliberately let sleep. */ + @Volatile private var rideActive = false + /** Bounds the screen-on skip to one interval; see the branch that uses it. */ + private var screenOnSkips = 0 + + private val keepAwakeTick = object : Runnable { + override fun run() { + if (!foreground || !Config(this@BridgeService).keepAwake) { karooDisconnect(); return } + // ONE policy with the wakelock idle guard. That guard releases the lock after + // WAKELOCK_IDLE_MS with no trainer, precisely so an abandoned session can sleep; keeping the + // whole DEVICE alive past that point would defeat it with a costlier resource. It is also the + // self-healing signal: noteTrainerLink() re-takes the lock the moment a trainer returns. + // (And once the lock is gone the CPU can suspend, which freezes this postDelayed anyway — + // uptimeMillis does not advance in suspend — so the poke could not be trusted regardless.) + val next = when { + wakeLock?.isHeld != true -> { FileLog.event("keep-awake: session idle — not poking"); KEEP_AWAKE_MS } + rideActive -> { FileLog.event("keep-awake: ride active — shutdown already suppressed"); KEEP_AWAKE_MS } + // Nothing to disarm while the screen is already awake — the countdown only starts when it + // sleeps. Matters when "keep this screen on" is also enabled: without this the poke fired + // every interval doing nothing, and the log said it had done something. + // NEVER twice running, though: isInteractive is a proxy, and AOSP counts a DREAMING state + // as interactive. If a firmware ever armed the countdown in a state that reads interactive, + // an unlimited skip would be the one error the 5-vs-10-minute margin cannot absorb — it + // would persist. A poke with the screen genuinely on is a no-op, so being wrong this way + // is free; being wrong the other way costs the device. + screenOn() && screenOnSkips == 0 -> { + screenOnSkips++ + FileLog.event("keep-awake: screen already on — no countdown to disarm, poke not needed") + KEEP_AWAKE_MS + } + else -> { screenOnSkips = 0; pokeScreen() } + } + handler.postDelayed(this, next) + } + } + + private fun screenOn(): Boolean = runCatching { + (getSystemService(POWER_SERVICE) as PowerManager).isInteractive + }.getOrDefault(false) // unknown -> poke anyway; a wasted wake beats a missed deadline + + /** @return the delay until the next attempt: a short retry if the host did not take the call. */ + private fun pokeScreen(): Long { + val ks = karooSystem + if (ks == null) { karooConnect(); return KEEP_AWAKE_RETRY_MS } + // dispatch() returns whether a controller RECEIVED the call — it is still no acknowledgement + // that the host acted on it, so this line says "submitted", never "the screen woke". + val taken = runCatching { ks.dispatch(io.hammerhead.karooext.models.TurnScreenOn) } + .onFailure { FileLog.event("keep-awake: TurnScreenOn threw — ${it.message}") } + .getOrDefault(false) + FileLog.event("keep-awake: TurnScreenOn submitted=$taken") + return if (taken) KEEP_AWAKE_MS else KEEP_AWAKE_RETRY_MS + } + + private fun karooConnect() { + if (karooSystem != null) return + val ks = io.hammerhead.karooext.KarooSystemService(this) + karooSystem = ks + runCatching { + ks.connect { ok -> + FileLog.event("keep-awake: Karoo system connected=$ok") + if (ok) runCatching { + ks.addConsumer { st -> + rideActive = st !is io.hammerhead.karooext.models.RideState.Idle + } + } + } + }.onFailure { FileLog.event("keep-awake: connect FAILED — ${it.message}"); karooSystem = null } + } + + private fun karooDisconnect() { + handler.removeCallbacks(keepAwakeTick) + // disconnect() unregisters every consumer with it; it also unbinds unconditionally, which throws + // if the bind never took — hence the guard. + karooSystem?.let { runCatching { it.disconnect() } } + karooSystem = null + rideActive = false + } + + /** Called at master-on and whenever config changes, so the toggle takes effect without a restart. + * Posts a tick in 20 s rather than waiting a full interval: a START_STICKY restart can land well into + * an already-running countdown. (That tick may SKIP if the screen is on — which is sound, because a + * countdown can only have been armed by the screen sleeping.) */ + private fun applyKeepAwake() { + handler.removeCallbacks(keepAwakeTick) + if (foreground && Config(this).keepAwake) { + screenOnSkips = 0 + karooConnect() + handler.postDelayed(keepAwakeTick, KEEP_AWAKE_RETRY_MS) + } else karooDisconnect() + } + + /** The Karoo powers ITSELF off when idle: HxStateManagerService flips "can shutdown" the moment the + * screen goes off, and with no ride recording it takes the device down — at any battery level. A + * wakelock cannot veto that; nothing an app can do can. What we CAN do is say so, because otherwise + * the log simply stops mid-line and a reader cannot tell a device shutdown from a crashed bridge. */ + private val shutdownReceiver = object : BroadcastReceiver() { + override fun onReceive(context: Context?, intent: Intent?) { + val battery = runCatching { + (getSystemService(BATTERY_SERVICE) as android.os.BatteryManager) + .getIntProperty(android.os.BatteryManager.BATTERY_PROPERTY_CAPACITY) + }.getOrDefault(-1) + // Synchronous: the log executor will not get another slice. + FileLog.eventNow("=== device ${intent?.action?.substringAfterLast('.') ?: "SHUTDOWN"} " + + "— uptime ${android.os.SystemClock.elapsedRealtime() / 60_000}m, battery $battery%, " + + "master=${Config(this@BridgeService).masterEnabled}, wake=${wakeLock?.isHeld == true}") + } + } + private val btStateReceiver = object : BroadcastReceiver() { override fun onReceive(c: Context?, intent: Intent?) { if (intent?.action != BluetoothAdapter.ACTION_STATE_CHANGED) return @@ -157,6 +328,13 @@ class BridgeService : Service() { // broadcast — guarded anyway, so adding a non-protected action here can't kill the service at birth. runCatching { registerReceiver(btStateReceiver, IntentFilter(BluetoothAdapter.ACTION_STATE_CHANGED)) } .onFailure { FileLog.event("bt state receiver not registered: ${it.message}") } + // ACTION_SHUTDOWN is not exempt from the implicit-broadcast ban, so it must be registered here + // rather than in the manifest — a manifest receiver would simply never fire. + runCatching { + registerReceiver(shutdownReceiver, IntentFilter(Intent.ACTION_SHUTDOWN).apply { + addAction(Intent.ACTION_REBOOT) + }) + }.onFailure { FileLog.event("shutdown receiver not registered: ${it.message}") } } override fun onBind(intent: Intent?): IBinder = binder @@ -166,13 +344,13 @@ class BridgeService : Service() { when (intent?.action) { ACTION_MASTER_ON -> { if (goForeground()) maybeStartReceive() } ACTION_MASTER_OFF -> { - stopEmit(); stopReceive(); releaseWakeLock() + stopEmit(); stopReceive(); releaseWakeLock(); karooDisconnect() Config(this).emitEnabled = false foreground = false ServiceCompat.stopForeground(this, ServiceCompat.STOP_FOREGROUND_REMOVE); stopSelf() } // master off: nothing to reconfigure, and don't leave an idle started service behind - ACTION_RECONFIGURE -> if (foreground) { FileLog.enabled = Config(this).loggingEnabled; applyConfigChange() } + ACTION_RECONFIGURE -> if (foreground) { FileLog.enabled = Config(this).loggingEnabled; applyConfigChange(); applyKeepAwake() } else if (!Config(this).masterEnabled) stopSelf() // don't kill a service the master wants alive ACTION_EMIT_START -> { if (foreground) startEmit() } // never emit from a non-foreground (master-off) service ACTION_EMIT_STOP -> { Config(this).emitEnabled = false; stopEmit() } @@ -195,6 +373,20 @@ class BridgeService : Service() { // Before the try, not after: the catch below logs WHY startForeground failed, and FileLog silently // drops anything written before init. One File object is not what blows the 5 s window. FileLog.init(this); FileLog.enabled = Config(this).loggingEnabled + // Session header. Two builds are now in play and a log with no version is a log you cannot trust to + // be about the code you think it is; the correction values matter because every wattage below is + // relative to them. + Config(this).let { c -> + // via PackageManager rather than BuildConfig: AGP 8 does not generate that class unless + // buildFeatures.buildConfig is turned on, and one log line does not justify a build change. + // versionName is nullable and the lookup can throw: both used to read as "vnull" in the header. + val ver = runCatching { packageManager.getPackageInfo(packageName, 0).versionName }.getOrNull() ?: "?" + FileLog.event("=== session start v$ver " + + "${android.os.Build.MODEL} api${android.os.Build.VERSION.SDK_INT} — " + + "scale=+${c.scaleAdjustPercent}% offset=${c.offsetW}W floor=${c.invertFloorW}W " + + "ergBias=${c.ergBiasW}W advName='${c.advertisedName}' sim=${c.simulate} ant=${c.antOutputEnabled}") + } + try { // connectedDevice only: dataSync would add a ~6h/24h cumulative FGS timeout on Android 14+ that // could kill the bridge mid-ride, and the BLE companion link doesn't need it. @@ -206,7 +398,15 @@ class BridgeService : Service() { status = getString(R.string.status_missing_bt_permission); listener?.invoke(); stopSelf(); return false } foreground = true - acquireWakeLock() + lastTrainerLinkMs = android.os.SystemClock.elapsedRealtime() + if (!acquireWakeLock()) { + foreground = false + status = getString(R.string.status_wakelock_failed); listener?.invoke() + ServiceCompat.stopForeground(this, ServiceCompat.STOP_FOREGROUND_REMOVE); stopSelf() + return false + } + applyKeepAwake() + handler.removeCallbacks(snapshot); handler.post(snapshot) // stops itself once foreground goes false return true } @@ -265,29 +465,68 @@ class BridgeService : Service() { if (client != null || simSource != null) return // idempotent val config = Config(this) config.lastSeenAddress = ""; config.lastSeenName = "" // runtime state; a process kill leaves it stale + pendingErgBias.reset() ErgBias.seed(config.ergBiasW) // start calibrated; there is no live command to measure against yet FileLog.event("receive start paired=${config.pairedAddress.ifEmpty { "any" }} sim=${config.simulate} ergBias=${config.ergBiasW}W") - val onProfile: (GattProfile) -> Unit = { profile -> lastProfile = profile; mirror?.build(profile) } + val owner = Any() + val sourceGeneration = ++receiveGeneration + receiveOwner.replace(owner) + // Low-rate callbacks still hop to main; onValue stays on the BLE thread and uses receiveOwner's + // monitor to make validation + mutation atomic with stopReceive(). + val onProfile: (GattProfile) -> Unit = { profile -> + // The worst of them: MirrorServer.build() is a one-shot latch, so a late profile from the source + // we just replaced wins it and the new source's real profile is then ignored for the session. + handler.post { receiveOwner.runIfCurrent(owner) { lastProfile = profile; mirror?.build(profile) } } + } val onValue: (java.util.UUID, ByteArray) -> Unit = { uuid, value -> - cacheForUi(config, uuid, value) - lastValues[uuid] = value // the one-shot reads happen long before Broadcast is pressed - mirror?.onZycleValue(uuid, value) + // Keep the 4 Hz relay off the main looper, but make ownership check + every source mutation one + // critical section. stopReceive() clears the same owner before teardown. + if (!receiveOwner.runIfCurrent(owner) { + cacheForUi(config, uuid, value) + lastValues[uuid] = value // the one-shot reads happen long before Broadcast is pressed + mirror?.onZycleValue(uuid, value) + }) staleCallbacks.incrementAndGet() // counted, not logged: it would be per-packet } val onState: (Boolean) -> Unit = { connected -> + handler.post { receiveOwner.runIfCurrent(owner) { zycleConnected = connected + if (connected) noteTrainerLink() // Only the DROP is immediate; going on the air waits for onSynced below. if (!connected) { zycleSynced = false; mirror?.setTrainerLinked(false); ErgBias.forget() } if (!connected) { config.lastSeenAddress = ""; config.lastSeenName = "" } // the config screen offers it only while live - status = if (connected) getString(R.string.status_trainer_connected) else getString(R.string.status_searching_trainer); listener?.invoke() } - val onSynced: () -> Unit = { zycleSynced = true; mirror?.setTrainerLinked(true) } + status = if (connected) getString(R.string.status_trainer_connected) else getString(R.string.status_searching_trainer); listener?.invoke() + } } + } + // Same treatment: a stale onSynced would put the mirror on the air with no trainer behind it, and + // setTrainerLinked is edge-triggered, so it would STAY there. + val onSynced: () -> Unit = { handler.post { receiveOwner.runIfCurrent(owner) { + val activeMirror = mirror + if (activeMirror != null && ftmsReleaseGeneration?.let { sourceGeneration >= it } == true) { + activeMirror.releaseFtmsQuarantine() + ftmsReleaseGeneration = null + } + zycleSynced = true + noteTrainerLink() + activeMirror?.setTrainerLinked(true) + } } } val c: TrainerSource = if (config.simulate) SimSource(onProfile, onValue, onState, onSynced).also { simSource = it } else ZycleClient(this, config.pairedAddress, onProfile, onValue, onState, onSynced, - onAdv = { bp -> lastAdvBlueprint = bp; mirror?.setAdvBlueprint(bp) }, // clone the trainer's real advertising - onFound = { name, addr -> config.lastSeenName = name ?: ""; config.lastSeenAddress = addr }) + // Guarded too, or the replaced source's advertising blueprint and address get written over the + // live one's. Neither needs a main-looper hop; the owner monitor provides the ordering. + onAdv = { bp -> receiveOwner.runIfCurrent(owner) { lastAdvBlueprint = bp; mirror?.setAdvBlueprint(bp) } }, + onFound = { name, addr -> receiveOwner.runIfCurrent(owner) { + // Binder thread: touch the @Volatile stamp only, never noteTrainerLink() — that would + // block a binder thread on the service monitor. A trainer stuck in a connect flap + // (status=133) is present, and must not be counted as absent by the idle guard. + lastTrainerLinkMs = android.os.SystemClock.elapsedRealtime() + config.lastSeenName = name ?: ""; config.lastSeenAddress = addr + } }) currentSourceKey = sourceKey(config) c.start() client = c - // after start(): SimSource reports connected synchronously, so don't overwrite it with "searching" + // SimSource reports connected synchronously inside start(), but onState now hops to main (see the + // lambdas above), so zycleConnected is still false here and this reads "searching". The posted body + // runs right after and corrects it — a one-frame flash, not a wrong end state. status = getString(if (zycleConnected) R.string.status_trainer_connected else R.string.status_searching_trainer) updateNotification(); listener?.invoke() } @@ -295,10 +534,16 @@ class BridgeService : Service() { private fun stopReceive() { if (client == null && simSource == null) return FileLog.event("receive stop") - ErgBias.forget() + receiveOwner.clear() // waits for an admitted callback, then rejects every later one mirror?.setTrainerLinked(false) // no source → nothing to advertise, whatever the call order Config(this).let { it.lastSeenAddress = ""; it.lastSeenName = "" } client?.stop(); client = null; simSource = null; lastProfile = null; lastAdvBlueprint = null; currentSourceKey = null + // Flush after client.stop() — but note stop() is NOT a callback barrier: a notification already past + // its `stopped` check can still publish a pending value after this runs, and that last whole-watt + // step is then lost. Immaterial (the EMA moves ~0.05 W a sample and is re-seeded next ride) and it is + // the SAFE direction: the dangerous half — a stale sample being persisted into the NEXT session — is + // closed by the receiveOwner guard on onValue, which is what feeds learnErgBias. + persistErgBias(Config(this)); ErgBias.forget() lastValues.clear() CorrectedFeed.clear() speedUnit = 0.01; speedUnitLocked = false; prevDistM = 0; prevElapsedS = 0 @@ -312,18 +557,51 @@ class BridgeService : Service() { if (mirror != null) return // idempotent val config = Config(this) FileLog.event("emit start scaleAdj=${config.scaleAdjustPercent}% offset=${config.offsetW}W") + val emitToken = Any() val m = MirrorServer( context = this, advertisedName = config.advertisedName, correction = { config.correction() }, - toZycle = { uuid, bytes, withResponse -> - if (com.enderthor.trainerbridgeble.ble.GattUuids.carriesControl(uuid)) { - // `bytes` is already inverse-corrected: exactly the raw watts the trainer is told to hold, - // which is what the measured power has to be compared against. + toZycle = { uuid, bytes, withResponse, onComplete -> + // CAPTURE the source under the owner; dispatch outside it (see [emitOwner]). A callback from + // a stopped mirror captures nothing and relays nothing; one admitted before the clear still + // targets the source it was admitted for, never the replacement. + var target: com.enderthor.trainerbridgeble.ble.TrainerSource? = null + emitOwner.runIfCurrent(emitToken) { target = client } + val source = target + if (source == null) { + onComplete(false) + false + } else source.write(uuid, bytes, withResponse) { success -> + // An accepted ATT write is NOT an accepted procedure: the trainer can still answer + // Control Not Permitted / Invalid Parameter. Committing here taught ERG bias from + // targets the machine refused. onControlAccepted below is the real commit point. + onComplete(success) + } + }, + onControlAccepted = { bytes -> + // Delivered on the trainer's binder thread. The mutations must happen UNDER the monitor, + // not after a check-then-act: stopEmit() runs on main and a callback that merely passed + // the check could otherwise publish into an already torn-down session. + var moved = false + emitOwner.runIfCurrent(emitToken) { + // `bytes` is already inverse-corrected: exactly the raw watts the trainer was told to + // hold, which is what measured power has to be compared against. ErgBias.onControl(bytes, android.os.SystemClock.elapsedRealtime()) - lastControl = describeControl(bytes); listener?.invoke() + lastControl = describeControl(bytes) + moved = true + } + if (moved) listener?.invoke() + }, + onTrainerRecycle = { + var current = false + emitOwner.runIfCurrent(emitToken) { current = true } + if (current && receiving) { + FileLog.event("FTMS origin disconnected mid-procedure — recycling trainer link") + ftmsReleaseGeneration = receiveGeneration + 1 + stopReceive() + maybeStartReceive() } - client?.write(uuid, bytes, withResponse) ?: false // false → the mirror answers the app with failure }, onStatus = { s -> status = s; listener?.invoke() }, onAdvState = { ok -> bleAdvOk = ok; listener?.invoke() }, @@ -332,6 +610,7 @@ class BridgeService : Service() { addr.equals(c.lastSeenAddress, true) || (c.pairedAddress.isNotEmpty() && addr.equals(c.pairedAddress, true)) }, ) + emitOwner.replace(emitToken) // published before start(): the constructor raises no callbacks mirror = m m.start() m.setTrainerLinked(zycleSynced) // Start pressed with the trainer already connected AND read @@ -375,6 +654,10 @@ class BridgeService : Service() { } private fun stopEmit() { + // Before the early return: a mirror whose construction or start() failed still left callbacks able + // to run against this token. + emitOwner.clear() + ftmsReleaseGeneration = null if (mirror == null) return FileLog.event("emit stop") mirror?.stop(); mirror = null @@ -408,7 +691,7 @@ class BridgeService : Service() { private fun cacheForUi(config: Config, uuid: java.util.UUID, value: ByteArray) { if (client == null && simSource == null) return // a late BLE callback after stopReceive() — no phantom if (uuid == com.enderthor.trainerbridgeble.ble.GattUuids.INDOOR_BIKE_DATA || - uuid == com.enderthor.trainerbridgeble.ble.GattUuids.CYCLING_POWER_MEASUREMENT) lastSampleMs = System.currentTimeMillis() + uuid == com.enderthor.trainerbridgeble.ble.GattUuids.CYCLING_POWER_MEASUREMENT) lastSampleMs = android.os.SystemClock.elapsedRealtime() when (uuid) { com.enderthor.trainerbridgeble.ble.GattUuids.INDOOR_BIKE_DATA -> { if (value.size < 2) return @@ -447,7 +730,7 @@ class BridgeService : Service() { // dropout would be transmitted as live. Speed/cadence still flow to the Karoo sensor. if (havePower) { sawIndoorBikeData = true // IBD really carries power — only now disable the CPM fallback - lastPowerMs = System.currentTimeMillis() // the clock powerFresh/freshPowerOrNull read + lastPowerMs = android.os.SystemClock.elapsedRealtime() // the clock powerFresh/freshPowerOrNull read } // ALWAYS report to ANT, with a null power once it has gone stale: gating the CALL froze // speed and cadence too and starved ANT on a trainer whose IBD carries no power field. @@ -457,16 +740,19 @@ class BridgeService : Service() { // A single truncated frame must not punch a hole in the recording, and a real dropout must // not be recorded as live watts: the grace window decides, not this one packet. CorrectedFeed.push(freshPowerOrNull(), lastSpeedKmh?.let { it / 3.6 }, lastCadence, android.os.SystemClock.elapsedRealtime()) - listener?.invoke() + // NOT listener?.invoke(): the Monitor already polls at 1 Hz, and driving it from here re-ran a + // full render (a fresh GradientDrawable + autosize on seven TextViews) at the trainer's ~4 Hz — + // on the same main looper the mirror's notify fan-out posts to. State CHANGES still notify + // immediately (connect/disconnect, control write, status, adv state); only the tiles wait. } com.enderthor.trainerbridgeble.ble.GattUuids.CYCLING_POWER_MEASUREMENT -> { if (!sawIndoorBikeData && value.size >= 4) { // fallback only if the trainer sends no IBD val raw = le16signed(value, 2); lastRawW = raw; lastCorrectedW = config.correction().correct(raw) learnErgBias(config, raw) - lastPowerMs = System.currentTimeMillis() + lastPowerMs = android.os.SystemClock.elapsedRealtime() antTx?.setLatest(PowerSample(freshPowerOrNull(), lastCadence, lastSpeedKmh?.let { it / 3.6 })) // ANT too, or FE-C stays blank CorrectedFeed.push(freshPowerOrNull(), lastSpeedKmh?.let { it / 3.6 }, lastCadence, android.os.SystemClock.elapsedRealtime()) - listener?.invoke() + // same as the IBD branch above: the 1 Hz poller owns the tiles } } } @@ -478,10 +764,24 @@ class BridgeService : Service() { // SimSource tracks the ERG target exactly, so it would teach a bias of ~0 and PERSIST it — running // the simulator for three minutes would quietly wipe the real trainer's calibration. if (config.simulate) return - ErgBias.onPower(raw, android.os.SystemClock.elapsedRealtime())?.let { - config.ergBiasW = it - FileLog.event("ERG bias learned: ${it}W (trainer settles above its command)") - } + val now = android.os.SystemClock.elapsedRealtime() + val due = pendingErgBias.onPower(raw, now) ?: return + // Rate-limited: onPower is fed at 4 Hz, and a converged bias sitting near an integer boundary (the + // measured overshoot is ~8 W) flips across it over and over — each flip a full rewrite+fsync of the + // prefs XML, in flash. The stated goal ("start the next ride where this one finished") is met just as + // well at one-minute granularity, and stopReceive flushes whatever is still pending. + persistErgBias(config, due) + } + + /** Write out the latest learned bias, if it moved since the last write. */ + private fun persistErgBias(config: Config) { + val w = pendingErgBias.drain() ?: return + persistErgBias(config, w) + } + + private fun persistErgBias(config: Config, w: Int) { + config.ergBiasW = w + FileLog.event("ERG bias learned: ${w}W (trainer settles above its command)") } private fun le16(b: ByteArray, i: Int) = (b[i].toInt() and 0xFF) or ((b[i + 1].toInt() and 0xFF) shl 8) @@ -489,21 +789,90 @@ class BridgeService : Service() { override fun onDestroy() { runCatching { unregisterReceiver(btStateReceiver) } - stopEmit(); stopReceive(); releaseWakeLock(); super.onDestroy() + runCatching { unregisterReceiver(shutdownReceiver) } + karooDisconnect() + stopEmit(); stopReceive(); releaseWakeLock() + foreground = false // ...or the snapshot keeps reposting itself and holds the Service alive + handler.removeCallbacks(snapshot) + super.onDestroy() } override fun onTimeout(startId: Int) { - stopEmit(); stopReceive(); releaseWakeLock() + stopEmit(); stopReceive(); releaseWakeLock(); karooDisconnect() foreground = false // or a later EMIT_START would pass the foreground gate on a dying service ServiceCompat.stopForeground(this, ServiceCompat.STOP_FOREGROUND_REMOVE); stopSelf() } - private fun acquireWakeLock() { - if (wakeLock?.isHeld == true) return - wakeLock = (getSystemService(POWER_SERVICE) as PowerManager) - .newWakeLock(PowerManager.PARTIAL_WAKE_LOCK, "TrainerBridgeBLE:session").also { runCatching { it.acquire() } } + /** elapsedRealtime of the last moment a trainer was linked, or of master-on. The lock is for an + * ACTIVE session: it must survive a trainer drop mid-ride, but not an evening of the master being + * left on with no trainer in the room, where it would block suspend for hours. */ + @Volatile private var lastTrainerLinkMs = 0L + + /** Called on every trainer link and once a minute while one is up. Re-takes the lock if the idle + * guard released it. A failure here only degrades the session — never tears it down, unlike the + * acquisition at master-on, because by this point a ride is already in progress. */ + private fun noteTrainerLink() { + lastTrainerLinkMs = android.os.SystemClock.elapsedRealtime() + if (foreground && wakeLock?.isHeld != true) acquireWakeLock("trainer back after idle release") } - private fun releaseWakeLock() { wakeLock?.let { if (it.isHeld) runCatching { it.release() } }; wakeLock = null } + @Synchronized private fun acquireWakeLock(why: String = "master active"): Boolean { + if (wakeLock?.isHeld == true) return true + val candidate = (getSystemService(POWER_SERVICE) as PowerManager) + .newWakeLock(PowerManager.PARTIAL_WAKE_LOCK, "TrainerBridgeBLE:session") + val failure = runCatching { candidate.acquire(); check(candidate.isHeld) { "lock not held" } }.exceptionOrNull() + if (failure != null) { + runCatching { if (candidate.isHeld) candidate.release() } + FileLog.event("wakelock ACQUIRE FAILED ($why): ${failure.message ?: failure.javaClass.simpleName}") + return false + } + wakeLock = candidate + FileLog.event("wakelock ACQUIRED ($why)") + return true + } + + @Synchronized private fun releaseWakeLock(why: String = "master inactive") { + val lock = wakeLock ?: return + val failure = runCatching { if (lock.isHeld) lock.release() }.exceptionOrNull() + val heldAfter = runCatching { lock.isHeld } + if (heldAfter.getOrNull() == false) { + wakeLock = null + FileLog.event("wakelock RELEASED ($why)") + } else { + val cause = failure ?: heldAfter.exceptionOrNull() + FileLog.event("wakelock RELEASE FAILED ($why): ${cause?.message ?: "lock still held"}") + } + } + + /** + * One compact state line a minute. Without it a quiet stretch of log is ambiguous — nothing happened, or + * the bridge stalled? — and every "permanent death" bug in this project's history looked exactly like + * silence. It also carries the values you would otherwise have to reconstruct: whether ERG is live, what + * the learner has settled on, and how far the level we SHOW has drifted from the machine's. + */ + private val snapshot = object : Runnable { + override fun run() { + if (!foreground) return // master off / service dying: stop the loop, don't outlive it + // Idle guard. A trainer drop mid-ride is seconds to minutes, so the whole-session hold that + // recovers from one is untouched; the master left on all afternoon is not, and that case used + // to block CPU suspend until someone remembered. Runs before the log line: it must not depend + // on diagnostics being switched on. + if (zycleConnected || zycleSynced) noteTrainerLink() + // Release ONLY once the controller is holding the search for us. With no scan registered, a + // postDelayed retry cannot wake a suspended CPU and the trainer's advertising has nowhere to + // land — the guard would trade battery drain for a bridge that never comes back. + else if (wakeLock?.isHeld == true && client?.searching == true && + android.os.SystemClock.elapsedRealtime() - lastTrainerLinkMs > WAKELOCK_IDLE_MS) + releaseWakeLock("idle: no trainer seen for ${WAKELOCK_IDLE_MS / 60_000}m") + if (FileLog.enabled) FileLog.event( + "state master=${Config(this@BridgeService).masterEnabled} recv=$receiving emit=$emitting " + + "trainer=${if (zycleSynced) "synced" else if (zycleConnected) "connected" else "-"} " + + "adv=$bleAdvOk apps=${mirror?.clientCount ?: 0} wake=${wakeLock?.isHeld == true} " + + "powerFresh=$powerFresh raw=$lastRawW corr=$lastCorrectedW cad=$lastCadence res=$resistance " + + "erg=${ErgBias.commanded} bias=${ErgBias.watts}W " + + "level=${mirror?.levelDebug ?: "-"} ant=${if (antEnabled) antOk else null} stale=${staleCallbacks.get()}") + handler.postDelayed(this, SNAPSHOT_MS) + } + } private fun createChannel() { val mgr = getSystemService(NotificationManager::class.java) @@ -533,6 +902,13 @@ class BridgeService : Service() { private const val BT_RESTART_SETTLE_MS = 2000L // let the BT stack settle before reopening the server private const val POWER_STALE_MS = 2000L // ~8 missed frames at 4 Hz: covers a hiccup, not a dropout private const val ANT_RESTART_DELAY_MS = 1500L // let the ANT service release the channel first + private const val ERG_BIAS_PERSIST_MS = 60_000L // at most one prefs write a minute; stopReceive flushes + private const val SNAPSHOT_MS = 60_000L // one state line a minute while the service is up + // Deliberately generous: a mechanical stop, a phone call or a bathroom break must NOT cost the + // lock mid-session. Only "left on and walked away" reaches this. NOT 30 min: that is exactly where + // Android 12 silently downgrades a long-running scan to opportunistic, and a device test could not + // then tell that apart from this release breaking rediscovery. + private const val WAKELOCK_IDLE_MS = 45 * 60_000L const val ACTION_MASTER_ON = "com.enderthor.trainerbridgeble.MASTER_ON" const val ACTION_MASTER_OFF = "com.enderthor.trainerbridgeble.MASTER_OFF" const val ACTION_EMIT_START = "com.enderthor.trainerbridgeble.EMIT_START" diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/Config.kt b/app/src/main/java/com/enderthor/trainerbridgeble/Config.kt index 5a7741d..1d5dc8c 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/Config.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/Config.kt @@ -67,6 +67,26 @@ class Config(context: Context) { set(v) = p.edit().putString(KEY_ADVNAME, v).apply() /** Write the diagnostic CSV log. */ + /** Poke the Karoo awake before its idle timer fires. `persist.hx.idle_shutdown_delay` is 600000 ms: + * ten minutes after the screen sleeps with no ride recording, HxStateManagerService powers the whole + * device off — at any battery level, and a running bridge does NOT count as activity. This dispatches + * the SDK's TurnScreenOn every 5 minutes, which resets that. + * COST, stated honestly: TurnScreenOn has no counterpart that turns it back off, so each poke costs + * one full device screen timeout (~1 min on a stock Karoo), not "a brief flash" — roughly a 20% + * screen duty cycle for as long as a trainer is linked. The screen is the biggest consumer on this + * device. It stops on the same leash as the wakelock guard, so an abandoned session still sleeps. */ + var keepAwake: Boolean + get() = p.getBoolean(KEY_KEEP_AWAKE, false) + set(v) = p.edit().putBoolean(KEY_KEEP_AWAKE, v).apply() + + /** Hold the screen on while the bridge is active. The Karoo powers ITSELF off when idle: its + * HxStateManagerService arms the shutdown the moment the screen sleeps, and with no ride recording + * it takes the device down at any battery level. Recording a ride prevents it — this is for the + * sessions where you don't. Costs real battery: the screen is the biggest consumer on the device. */ + var keepScreenOn: Boolean + get() = p.getBoolean(KEY_KEEP_SCREEN, false) + set(v) = p.edit().putBoolean(KEY_KEEP_SCREEN, v).apply() + var loggingEnabled: Boolean get() = p.getBoolean(KEY_LOG, false) set(v) = p.edit().putBoolean(KEY_LOG, v).apply() @@ -111,6 +131,8 @@ class Config(context: Context) { const val KEY_NAME = "pairedName" const val KEY_ADVNAME = "advertisedName" const val KEY_LOG = "loggingEnabled" + const val KEY_KEEP_SCREEN = "keepScreenOn" + const val KEY_KEEP_AWAKE = "keepAwake" const val KEY_SIM = "simulate" const val KEY_ANT = "antOutput" const val KEY_ANT_ID = "antDeviceId" diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/ConfigActivity.kt b/app/src/main/java/com/enderthor/trainerbridgeble/ConfigActivity.kt index a51ba7c..24028ab 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/ConfigActivity.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/ConfigActivity.kt @@ -27,6 +27,8 @@ class ConfigActivity : Activity() { private lateinit var scanBtn: TextView private lateinit var foundList: LinearLayout private lateinit var inUseBox: LinearLayout + private lateinit var keepAwakeCheck: android.widget.CheckBox + private lateinit var keepScreenCheck: android.widget.CheckBox private lateinit var logCheck: android.widget.CheckBox private lateinit var simCheck: android.widget.CheckBox private lateinit var antCheck: android.widget.CheckBox @@ -85,6 +87,8 @@ class ConfigActivity : Activity() { // Toggles val opt = card(getString(R.string.config_options)) + keepAwakeCheck = check(getString(R.string.config_keep_awake), config.keepAwake); opt.addView(keepAwakeCheck) + keepScreenCheck = check(getString(R.string.config_keep_screen), config.keepScreenOn); opt.addView(keepScreenCheck) logCheck = check(getString(R.string.config_log), config.loggingEnabled); opt.addView(logCheck) simCheck = check(getString(R.string.config_sim), config.simulate); opt.addView(simCheck) antCheck = check(getString(R.string.config_ant_output), config.antOutputEnabled); opt.addView(antCheck) @@ -116,6 +120,8 @@ class ConfigActivity : Activity() { intField(offsetField, getString(R.string.config_offset_label), { true }) { config.offsetW = it } intField(floorField, getString(R.string.config_floor_label), { it >= 0 }) { config.invertFloorW = it } config.advertisedName = nameField.text.toString().trim() // blank = keep the device's own name + config.keepAwake = keepAwakeCheck.isChecked + config.keepScreenOn = keepScreenCheck.isChecked config.loggingEnabled = logCheck.isChecked config.simulate = simCheck.isChecked config.antOutputEnabled = antCheck.isChecked diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/FileLog.kt b/app/src/main/java/com/enderthor/trainerbridgeble/FileLog.kt index b0735d6..19ad935 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/FileLog.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/FileLog.kt @@ -13,6 +13,10 @@ object FileLog { @Volatile var enabled = false @Volatile private var file: File? = null private val io = Executors.newSingleThreadExecutor() + /** Every mutation of the file goes through this: the executor's append+rotate and the synchronous + * shutdown line write the same path, and a rotation racing that line would lose the one record that + * tells a device shutdown apart from a crashed bridge. */ + private val fileLock = Any() fun init(context: Context) { if (file != null) return @@ -24,7 +28,7 @@ object FileLog { val f = file ?: return val ts = System.currentTimeMillis() // when it HAPPENED — the IO queue can lag under load io.execute { - runCatching { + runCatching { synchronized(fileLock) { // Nothing is throttled (a dropped line is the one you needed), so cap the file instead. // Rotate rather than truncate: truncating at the cap leaves you holding a log that starts // seconds ago, which is worthless for a ride that just ended. O(1) — a rename, no read. @@ -36,11 +40,22 @@ object FileLog { if (rotated) f.writeText("# $ts log rotated at ${MAX_BYTES / 1024 / 1024} MB (previous: ${f.name}.1)\n") } f.appendText("# $ts $msg\n") - } + } } } } - private const val MAX_BYTES = 16L * 1024 * 1024 // two files kept, so 32 MB total + /** Synchronous append, for the one case where the queue will never drain: the device is powering + * off and we have seconds. Blocks the caller — never use it on a BLE callback or the hot path. */ + fun eventNow(msg: String) { + if (!enabled) return + val f = file ?: return + runCatching { synchronized(fileLock) { f.appendText("# ${System.currentTimeMillis()} $msg\n") } } + } + + // Every notification is logged unthrottled (~2 KB/s), so 16 MB filled in ~2 h and rotation threw away + // the START of the ride — which is exactly where the connect / sync / first-advertise sequence lives, + // the part you turned logging on to see. 48 MB holds a ~6 h ride in one file, 12 h across the two. + private const val MAX_BYTES = 48L * 1024 * 1024 // two files kept, so 96 MB worst case fun clear() { file?.let { f -> io.execute { runCatching { f.writeText("") } } } } diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/MonitorActivity.kt b/app/src/main/java/com/enderthor/trainerbridgeble/MonitorActivity.kt index 0e4a2b9..b4f535c 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/MonitorActivity.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/MonitorActivity.kt @@ -133,7 +133,17 @@ class MonitorActivity : Activity() { render() } + /** Only while the master is ON: leaving the app open with the bridge idle should not pin the screen. + * This is the whole mitigation — the Karoo's shutdown is armed by the screen going off, so a screen + * that never sleeps never arms it. Nothing an app can do can veto the shutdown once it starts. */ + private fun applyKeepScreenOn() { + val hold = config.keepScreenOn && config.masterEnabled + if (hold) window.addFlags(android.view.WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON) + else window.clearFlags(android.view.WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON) + } + private fun render() { + applyKeepScreenOn() val s = service val master = config.masterEnabled val emitting = s?.emitting == true @@ -143,7 +153,7 @@ class MonitorActivity : Activity() { startBtn.isEnabled = canEmit; startBtn.alpha = if (canEmit) 1f else 0.4f // Fresh = a sample arrived within the last 3s. A brief (<3s) blip keeps showing the last value // (the mirror is re-emitting it too); a longer gap blanks the tiles to "—". - val fresh = s != null && s.lastSampleMs != 0L && System.currentTimeMillis() - s.lastSampleMs <= STALE_MS + val fresh = s != null && s.lastSampleMs != 0L && android.os.SystemClock.elapsedRealtime() - s.lastSampleMs <= STALE_MS // Banner shows the TRAINER (receive) link when master is on; "Off" when master is off. val (bText, bColor) = when { !master -> getString(R.string.monitor_off) to Palette.MUTED diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/RuntimeHardening.kt b/app/src/main/java/com/enderthor/trainerbridgeble/RuntimeHardening.kt new file mode 100644 index 0000000..1d3c08f --- /dev/null +++ b/app/src/main/java/com/enderthor/trainerbridgeble/RuntimeHardening.kt @@ -0,0 +1,284 @@ +package com.enderthor.trainerbridgeble + +internal class TrainerWriteTicket( + val sequence: Long, + private val onComplete: (Boolean) -> Unit, +) { + private val completed = java.util.concurrent.atomic.AtomicBoolean(false) + fun complete(success: Boolean): Boolean { + if (!completed.compareAndSet(false, true)) return false + onComplete(success) + return true + } +} + +internal fun encodeTargetResistance(target: Int): ByteArray { + val value = target.coerceIn(Short.MIN_VALUE.toInt(), Short.MAX_VALUE.toInt()) + return byteArrayOf(0x04, (value and 0xFF).toByte(), ((value ushr 8) and 0xFF).toByte()) +} + +internal class FtmsBootstrapReadiness( + val controllable: Boolean, +) { + var featureRead = false + var controlPointSubscribed = false + var indoorBikeSubscribed = false + var cyclingPowerSubscribed = false + + val ready: Boolean get() = + (!controllable || featureRead && controlPointSubscribed) && + (indoorBikeSubscribed || cyclingPowerSubscribed) + + val missingRequirements: List get() = buildList { + if (controllable && !featureRead) add("FTMS Feature read") + if (controllable && !controlPointSubscribed) add("FTMS Control Point subscription") + if (!indoorBikeSubscribed && !cyclingPowerSubscribed) add("Indoor Bike or Cycling Power subscription") + } +} + +/** Single owner of "who may drive the trainer". It also owns the per-connection identities and the + * in-flight procedure's payload, because every decision needs them together: looking a client up in one + * map and admitting it under a different lock let a disconnect land in between; keeping the command bytes + * in a side slot let one procedure's response commit another procedure's target. Identity, admission, + * payload and termination are all ONE synchronized transition here. */ +internal class FtmsControlCoordinator { + data class Client(val address: String, val generation: Long) + /** `id` makes every admitted procedure unique: two same-opcode procedures are NOT interchangeable, so a + * late transport failure or an expired deadline for the first cannot terminate the second. */ + data class Procedure(val client: Client?, val opcode: Int, val id: Long) + /** A procedure that just ended, with the exact bytes it carried. Non-null even for a local procedure + * (whose `client` is legitimately null) so callers can tell "matched" from "already gone". */ + /** Deliberately NOT a data class: it carries a ByteArray, whose generated equals/hashCode would be + * identity-based and quietly wrong for anyone who later compares or keys on one. */ + class Terminated(val procedure: Procedure, val bytes: ByteArray?) { + val client: Client? get() = procedure.client + } + + sealed interface Admission { + data class Admitted(val procedure: Procedure) : Admission + data class Rejected(val result: Int, val client: Client?) : Admission + } + + private var owner: Client? = null + private var pending: Procedure? = null + private var pendingBytes: ByteArray? = null + private var invalidSession = false + private var generations = 0L + private var procedures = 0L + private val keys = HashMap() + + @Synchronized fun connected(address: String): Client = + Client(address, ++generations).also { keys[address] = it } + + @Synchronized fun identity(address: String): Client? = keys[address] + + /** True only while this exact procedure is the admitted one. An arm that lost a race to the main + * looper must ask before replacing the live deadline — otherwise it cancels a healthy procedure's + * only timer and installs one for a procedure that already ended. */ + @Synchronized fun isPending(procedure: Procedure): Boolean = pending == procedure + + /** True while this client holds control. A terminal result that was produced while the client was + * NOT the owner carries no authority to release ownership it may have acquired since. */ + @Synchronized fun owns(client: Client): Boolean = owner == client + + /** Key removal and ownership loss as ONE transition; returns the procedure that died with it, if any. */ + @Synchronized fun disconnected(address: String): Terminated? { + val client = keys.remove(address) ?: return null + if (owner == client) owner = null + val lost = pending?.takeIf { it.client == client } ?: return null + val terminated = Terminated(lost, pendingBytes) + pending = null; pendingBytes = null; invalidSession = true + return terminated + } + + /** Admit by ADDRESS so the identity lookup and the decision cannot straddle a disconnect. + * Returns null only when the address has no live connection — callers must fail closed, never + * mint an identity from a write, or a departing client can be resurrected and take ownership. */ + @Synchronized fun admit(address: String, opcode: Int, bytes: ByteArray?): Admission? { + val client = keys[address] ?: return null + if (invalidSession || pending != null) return Admission.Rejected(OPERATION_FAILED, client) + if (if (opcode == REQUEST_CONTROL) owner != null && owner != client else owner != client) + return Admission.Rejected(CONTROL_NOT_PERMITTED, client) + return Procedure(client, opcode, ++procedures).let { + pending = it; pendingBytes = bytes; Admission.Admitted(it) + } + } + + @Synchronized fun admitLocal(opcode: Int, bytes: ByteArray?): Procedure? { + if (invalidSession || owner != null || pending != null) return null + return Procedure(null, opcode, ++procedures).also { pending = it; pendingBytes = bytes } + } + + /** Terminates exactly the procedure named — never a newer one that reused the opcode. */ + @Synchronized fun transportFailed(procedure: Procedure): Terminated? { + if (pending != procedure) return null + val terminated = Terminated(procedure, pendingBytes) + pending = null; pendingBytes = null + return terminated + } + + /** No FTMS response arrived in time. A late opcode-only response can no longer be correlated to a + * request, so the trainer session is quarantined exactly as it is for a controller that vanished + * mid-procedure. Returns non-null whenever it MATCHED, including a local procedure with no client — + * a null return means "not the pending procedure", and only that may skip the recovery. */ + @Synchronized fun timedOut(procedure: Procedure): Terminated? { + if (pending != procedure) return null + val terminated = Terminated(procedure, pendingBytes) + pending = null; pendingBytes = null; invalidSession = true + return terminated + } + + /** Returns the procedure the response terminated together with the bytes it carried, so the caller + * commits the target that was actually acknowledged and cancels the right deadline. */ + @Synchronized fun response(opcode: Int, result: Int): Terminated? { + if (invalidSession) return null + val procedure = pending?.takeIf { it.opcode == opcode } ?: return null + val terminated = Terminated(procedure, pendingBytes) + pending = null; pendingBytes = null + if (procedure.client != null && opcode == REQUEST_CONTROL && result == SUCCESS) owner = procedure.client + return terminated + } + + /** The owner could not be told the outcome; drop its claim so the next requester can arbitrate. */ + @Synchronized fun releaseOwner(client: Client): Boolean { + if (owner != client) return false + owner = null + return true + } + + @Synchronized fun trainerDropped(): Client? = owner.also { + owner = null; pending = null; pendingBytes = null + } + + @Synchronized fun trainerReady() { invalidSession = false } + + /** Full teardown, used by BOTH stop() and a local GATT server rebuild. Closing the server invalidates + * every ATT handle and delivers no disconnect callbacks, so keeping any of this would strand ownership + * on a generation that can never come back. */ + @Synchronized fun clear() { + owner = null; pending = null; pendingBytes = null; invalidSession = false; keys.clear() + } + + companion object { + const val SUCCESS = 0x01 + const val OPERATION_FAILED = 0x04 + const val CONTROL_NOT_PERMITTED = 0x05 + private const val REQUEST_CONTROL = 0x00 + } +} + +internal class IdentityOwner { + @Volatile private var value: T? = null + + val current: T? get() = value + + @Synchronized fun replace(next: T?): T? = value.also { value = next } + + @Synchronized fun clear(): T? = value.also { value = null } + + @Synchronized fun clearIfCurrent(candidate: T, action: () -> Unit): Boolean { + if (value !== candidate) return false + value = null + action() + return true + } + + @Synchronized fun runIfCurrent(candidate: T, action: () -> Unit): Boolean { + if (value !== candidate) return false + action() + return true + } +} + +internal class GattSessionCoordinator( + private val resetRuntime: () -> Unit, + private val disconnect: (T) -> Unit, + private val close: (T) -> Unit, + private val reconnect: () -> Unit, +) { + private val owner = IdentityOwner() + + val current: T? get() = owner.current + fun replace(next: T?) = owner.replace(next) + fun clear() = owner.clear() + fun clearIfCurrent(candidate: T, action: () -> Unit) = owner.clearIfCurrent(candidate, action) + fun runIfCurrent(candidate: T, action: () -> Unit) = owner.runIfCurrent(candidate, action) + + fun retireIfCurrent(candidate: T, onRetiring: () -> Unit = {}): Boolean { + if (!owner.clearIfCurrent(candidate) { onRetiring(); resetRuntime() }) return false + disconnect(candidate) + close(candidate) + reconnect() + return true + } + + /** + * A timed-out op MUST retire the handle, not just advance the queue. Unsticking in place cannot cancel + * the operation Android still has, so its late callback is indistinguishable from the callback for the + * op dispatched in its place: that one completes the wrong op, cancels the wrong watchdog, and pumps a + * third while the second is still on the controller. Deferring the retirement to an Nth CONSECUTIVE + * timeout does not work either — the same late callback resets any such counter, so the escalation + * never fires precisely when the handle is wedged. A reconnect is the cheaper failure. + */ + fun timeoutIfCurrent(candidate: T, stillPending: () -> Boolean, onRetiring: () -> Unit = {}): Boolean { + var timedOut = false + owner.runIfCurrent(candidate) { + if (stillPending()) timedOut = owner.clearIfCurrent(candidate) { onRetiring(); resetRuntime() } + } + if (!timedOut) return false + disconnect(candidate) + close(candidate) + reconnect() + return true + } +} + +internal class AdvertisingAttemptCoordinator { + private val owner = IdentityOwner() + + val current: T? get() = owner.current + fun runIfCurrent(candidate: T, action: () -> Unit) = owner.runIfCurrent(candidate, action) + fun clearIfCurrent(candidate: T, action: () -> Unit) = owner.clearIfCurrent(candidate, action) + fun clear() = owner.clear() + + @Synchronized fun begin(next: T, retire: (T) -> Unit) { + owner.clear()?.let(retire) + owner.replace(next) + } + + fun retireIfCurrent(candidate: T, retire: (T) -> Unit, after: () -> Unit): Boolean { + if (!owner.clearIfCurrent(candidate) {}) return false + retire(candidate) + after() + return true + } + + fun failIfCurrent( + candidate: T, + stop: (T) -> Unit, + markFailed: () -> Unit, + retry: () -> Unit, + ): Boolean = retireIfCurrent(candidate, stop) { markFailed(); retry() } +} + +internal class ErgBiasPersistence( + private val persistIntervalMs: Long, + private val learner: (rawWatts: Int, nowMs: Long) -> Int?, +) { + private var pending: Int? = null + private var lastPersistMs: Long? = null + + fun reset() { pending = null; lastPersistMs = null } + + fun onPower(rawWatts: Int, nowMs: Long): Int? { + val newWholeWatt = learner(rawWatts, nowMs) + if (newWholeWatt != null) pending = newWholeWatt + val value = pending ?: return null + if (lastPersistMs?.let { nowMs - it < persistIntervalMs } == true) return null + pending = null + lastPersistMs = nowMs + return value + } + + fun drain(): Int? = pending.also { pending = null } +} diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/ant/RawAntLink.kt b/app/src/main/java/com/enderthor/trainerbridgeble/ant/RawAntLink.kt index eecd8e0..399b3cd 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/ant/RawAntLink.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/ant/RawAntLink.kt @@ -84,7 +84,8 @@ class RawAntLink( * bidirectional slave to send acknowledged control data from its own thread; tolerates null. */ val currentChannel: AntChannel? get() = channel - /** Wall-clock of the last message from the current channel; 0 when none since (re)open. Drives the + /** elapsedRealtime (NOT wall-clock — a clock re-sync must not move a timeout) of the last message from + * the current channel; 0 when none since (re)open. Drives the * heartbeat watchdog: a SLAVE that acquires a master then goes silent while still "tracking" emits * neither RX_SEARCH_TIMEOUT nor onChannelDeath, so nothing else would recover it. Masters get a TX * event every period, so their heartbeat never expires. */ @@ -130,9 +131,9 @@ class RawAntLink( delay(HEARTBEAT_CHECK_MS) val last = lastMessageMs if (!stopped && channel != null && !opening.get() && last != 0L && - System.currentTimeMillis() - last > HEARTBEAT_TIMEOUT_MS + android.os.SystemClock.elapsedRealtime() - last > HEARTBEAT_TIMEOUT_MS ) { - Log.i(tag, "silent ${System.currentTimeMillis() - last}ms — recycling") + Log.i(tag, "silent ${android.os.SystemClock.elapsedRealtime() - last}ms — recycling") lastMessageMs = 0L val dead = channel; channel = null; releaseChannel(dead) scheduleReopen("heartbeat") @@ -161,7 +162,7 @@ class RawAntLink( ch.setChannelEventHandler(object : IAntChannelEventHandler { override fun onReceiveMessage(type: MessageFromAntType?, msg: AntMessageParcel?) { if (msg == null || type == null || ch !== channel) return - lastMessageMs = System.currentTimeMillis() + lastMessageMs = android.os.SystemClock.elapsedRealtime() // The slave's search window expiring closes the channel as a CHANNEL_EVENT // (never onChannelDeath). Consume it here and reopen, else the channel is dead // for the rest of the session. Any other CHANNEL_EVENT (e.g. master TX) and all diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/ble/MirrorServer.kt b/app/src/main/java/com/enderthor/trainerbridgeble/ble/MirrorServer.kt index 4c9aadd..f49f1b5 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/ble/MirrorServer.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/ble/MirrorServer.kt @@ -10,7 +10,9 @@ import android.bluetooth.BluetoothGattServerCallback import android.bluetooth.BluetoothGattService import android.bluetooth.BluetoothManager import android.bluetooth.le.AdvertiseData +import android.bluetooth.le.AdvertiseCallback import android.bluetooth.le.AdvertiseSettings +import android.bluetooth.le.BluetoothLeAdvertiser import android.content.Context import android.os.Build import android.os.Handler @@ -18,7 +20,10 @@ import android.os.Looper import android.os.ParcelUuid import android.os.SystemClock import android.util.Log +import com.enderthor.trainerbridgeble.AdvertisingAttemptCoordinator import com.enderthor.trainerbridgeble.FileLog +import com.enderthor.trainerbridgeble.FtmsControlCoordinator +import com.enderthor.trainerbridgeble.IdentityOwner import com.enderthor.trainerbridgeble.R import com.enderthor.trainerbridgeble.correction.PowerCorrection import java.util.ArrayDeque @@ -32,14 +37,18 @@ import java.util.concurrent.ConcurrentHashMap * ERG target inverse-corrected on control writes). Serves multiple centrals at once. * * @param correction supplies the LIVE correction (config may change mid-session). - * @param toZycle forwards an app write to the trainer's matching characteristic. + * @param toZycle forwards an app write to the trainer's matching characteristic and reports its terminal result. */ @SuppressLint("MissingPermission") class MirrorServer( private val context: Context, private val advertisedName: String, private val correction: () -> PowerCorrection, - private val toZycle: (charUuid: UUID, bytes: ByteArray, withResponse: Boolean) -> Boolean, + private val toZycle: (charUuid: UUID, bytes: ByteArray, withResponse: Boolean, onComplete: (Boolean) -> Unit) -> Boolean, + private val onTrainerRecycle: () -> Unit = {}, + /** The trainer ACCEPTED a control procedure (FTMS Response Code = SUCCESS) with these exact bytes. + * ERG bias learning and the UI must hang off this, not off the ATT write callback. */ + private val onControlAccepted: (ByteArray) -> Unit = {}, private val onStatus: (String) -> Unit = {}, /** Health report to the UI: true once we're actually advertising; false if the server/advertising fails. */ private val onAdvState: (Boolean) -> Unit = {}, @@ -58,34 +67,65 @@ class MirrorServer( private val cache = ConcurrentHashMap() // last value (power corrected) private val subscribers = ConcurrentHashMap>() // char uuid → subscribed client addrs private val clients = ConcurrentHashMap() // connected centrals + private val ftmsControl = FtmsControlCoordinator() + /** Deadline for the admitted FTMS procedure. Without it one unanswered Control Point response wedges + * the gate and every later request — Request Control included — is refused for the rest of the ride. */ + /** The live procedure and its timer, kept together so a cancellation can prove it owns the deadline. + * Mostly main-looper, but rebuildServer() reaches it from a binder thread, hence @Volatile. */ + @Volatile private var procedureDeadline: Pair? = null + /** The client whose TERMINAL Control Point result is currently in flight, so a later failure report + * from onNotificationSent can be attributed. Measurement notifications never set this. */ + @Volatile private var terminalIndication: FtmsControlCoordinator.Client? = null // touched from the GATT server binder thread, the client's binder thread and main — a plain ArrayDeque // can throw mid-poll when stop() clears it, and an exception on a binder callback kills the process private val pendingServices = java.util.concurrent.ConcurrentLinkedDeque() + // Armed only AFTER the trainer write completes, so it measures the machine and not our own op queue. + // FTMS conformance ties the collector's wait to the ATT transaction timeout (~30 s); anything shorter + // recycles the trainer link on a healthy-but-slow machine, which costs the rider far more than waiting. + private val PROCEDURE_TIMEOUT_MS = 30_000L private val ADV_RESTART_MS = 250L private val ADV_RETRY_MS = 1000L - private val ADV_MAX_RETRIES = 5 + private val ADV_RETRY_MAX_MS = 30_000L // backoff ceiling; there is no attempt cap (see scheduleAdvRetry) private val SERVICE_RETRY_MS = 300L private val SERVICE_MAX_RETRIES = 5 - private val ADV_START_TIMEOUT_MS = 3000L - private val ADV_LATE_STOP_MS = 1500L + private val SERVICE_ADD_TIMEOUT_MS = 8000L + private val SERVICE_REBUILD_MS = 2000L + private val SERVICE_REBUILD_MAX_MS = 30_000L + // Generous on purpose: this must only ever fire for a callback that is genuinely LOST (adapter off, BT + // process died). Firing it for one that is merely slow starts a second attempt against the same shared + // callback object — see scheduleAdvRetry's note. + private val ADV_START_TIMEOUT_MS = 8000L + private val SERVER_RETRY_MS = 2000L + private val SERVER_RETRY_MAX_MS = 30_000L // Bluetooth off is a whole-ride failure, not a hiccup + /** First re-stop of an orphan; doubles to [ADV_SWEEP_MAX_MS] while any remain. Not a bound on when the + * stack answers a start — there is none — just the rate at which we keep asking. */ + private val ADV_SWEEP_MS = 1000L + private val ADV_SWEEP_MAX_MS = 30000L /** How long after a control write the trainer's level is still settling on it. Observed on the 28-jul * ride: every servo-driven level step landed 0.19-2.6 s after the write that caused it. */ private val LEVEL_SETTLE_MS = 3000L @Volatile private var serviceRetries = 0 private val serviceRetryRunnable = Runnable { if (server != null) addNextService() } + private val serviceAddOwner = IdentityOwner() + @Volatile private var serviceAddWatchdog: Runnable? = null + @Volatile private var serviceRebuildMs = SERVICE_REBUILD_MS private val ADVERTISE_FAILED_DATA_TOO_LARGE = 1 private val cccd: UUID = UUID.fromString("00002902-0000-1000-8000-00805f9b34fb") private val ATT_UNLIKELY_ERROR = 0x0E private val ATT_INVALID_OFFSET = 0x07 + private val ATT_REQUEST_NOT_SUPPORTED = 0x06 + private val ATT_INVALID_ATTRIBUTE_VALUE_LENGTH = 0x0D private var originalName: String? = null @Volatile private var advertising = false @Volatile private var advStarting = false // a start is in flight; `advertising` only flips in the callback + private val advAttempts = AdvertisingAttemptCoordinator() private val built = java.util.concurrent.atomic.AtomicBoolean(false) // build the mirrored GATT once; a trainer reconnect keeps it @Volatile private var advBlueprint: AdvBlueprint? = null // the trainer's real advertising, to clone @Volatile private var trainerLinked = false // advertise only while a trainer is actually feeding us @Volatile private var servicesReady = false // every mirrored service has been ADDED (built != added) - @Volatile private var advRetries = 0 + @Volatile private var advRetries = 0 // diagnostic count only; the retry policy is advRetryMs + @Volatile private var advRetryMs = ADV_RETRY_MS @Volatile private var dropNameFromAdv = false // set after DATA_TOO_LARGE: the packet won't fit the name @Volatile private var dropMfrFromAdv = false // shed the cloned manufacturer data first @Volatile private var dropBlueprintFromAdv = false // then the cloned UUIDs, falling back to the standard pair @@ -94,34 +134,97 @@ class MirrorServer( * starts advertising again the moment it drops — so advertising with no trainer behind us puts two * identical devices in the air and lets an app bind to a bridge that has no data to give it. */ fun setTrainerLinked(linked: Boolean) { - if (trainerLinked == linked) return + val controller = if (linked) null else ftmsControl.trainerDropped() + if (trainerLinked == linked) { + controller?.let { handler.post { cancelClient(it) } } + return + } trainerLinked = linked + // Losing the trainer invalidates the level anchor (see [reanchorLevel]) AND any servo step we were + // still owed: the write that bought it may never have reached the trainer, and if it did, the step it + // caused is on the far side of the outage where the re-anchor absorbs it anyway. Leaving it armed + // means the rider's first press after a fast reconnect is eaten instead — and this codebase's settled + // bias is that eating a real press is the worse failure (pinning the byte killed the buttons). + // Getting the link back also deserves a fresh advertise backoff. + if (!linked) { reanchorLevel = true; servoStepOwed = false; lastControlWriteMs = 0L } + else { advRetries = 0; advRetryMs = ADV_RETRY_MS } FileLog.event("mirror trainer link=$linked -> ${if (linked) "advertise" else "stop advertising"}") - handler.post { if (linked) startAdvertising() else stopAdvertising() } + handler.post { + if (linked) startAdvertising() else { + stopAdvertising() + controller?.let { cancelClient(it) } + } + } } /** Adopt the trainer's own advertised service UUIDs + manufacturer data (captured by the client) so we * advertise an identical packet. If we're already advertising, restart to apply it. */ fun setAdvBlueprint(bp: AdvBlueprint) { advBlueprint = bp - advRetries = 0 // a new blueprint deserves a fresh retry budget — but keep what we learned about size + // A new blueprint deserves a fresh retry budget — and that means the BACKOFF, not just the diagnostic + // count: at the 30 s ceiling, resetting only the counter changed nothing. Keep the size shedding. + advRetries = 0; advRetryMs = ADV_RETRY_MS FileLog.event("mirror adv blueprint: ${bp.serviceUuids.size} uuids, ${bp.manufacturerData.size} mfr") handler.post { if (advertising) restartAdvertising() } // serialise onto the advertising thread } fun start() { + stopped = false // Kill any advertising set left running by a PREVIOUS instance: its stop may have been dropped // because a start was still in flight, and its callback died with the object. - lastAdvCallback?.takeIf { it !== advCallback }?.let { orphan -> - FileLog.event("stopping an advertising set left by a previous mirror") - runCatching { adapter.bluetoothLeAdvertiser?.stopAdvertising(orphan) } + lastAdvCallback?.let { orphan -> + FileLog.event("stopping an advertising set left by a previous mirror (unresolved=$lastAdvUnresolved)") + // Only an unresolved start can have its stop dropped, so only that one needs the sweep. A + // resolved one is stopped once, reliably — adopting it would strand it in advOrphans forever. + if (lastAdvUnresolved) orphanAdvCallback(orphan) + else { + runCatching { adapter.bluetoothLeAdvertiser?.stopAdvertising(orphan) } + if (lastAdvCallback === orphan) lastAdvCallback = null + } + } + if (advOrphans.isNotEmpty()) { // orphans from an earlier instance keep being swept by this one + advSweepMs = ADV_SWEEP_MS + orphanHandler.removeCallbacks(advSweep); orphanHandler.postDelayed(advSweep, advSweepMs) } + openServer() + } + + /** Open the GATT server, retrying while emit is on. A null here is usually the stack restarting, and + * returning on it left the whole emit half dead for the session with no path back — [build] had already + * been called by then, so even a later recovery would have had nothing to serve. Hence [pendingProfile]. */ + private fun openServer() { + if (stopped || server != null) return val srv = runCatching { mgr.openGattServer(context, serverCallback) }.getOrNull() - if (srv == null) { onStatus(context.getString(R.string.status_ble_server_failed)); onAdvState(false); return } - server = srv + if (srv == null) { + // Backoff, not a flat retry: the common cause (Bluetooth off, stack not coming back) lasts the + // whole ride, and at a fixed 2 s that is ~1800 attempts an hour, each one a log line — the same + // mistake RawAntLink.scheduleReopen already documents having made. + val wait = serverRetryMs + serverRetryMs = (wait * 2).coerceAtMost(SERVER_RETRY_MAX_MS) + FileLog.event("openGattServer returned null — retrying in ${wait}ms") + onStatus(context.getString(R.string.status_ble_server_failed)); onAdvState(false) + handler.removeCallbacks(serverRetryRunnable); handler.postDelayed(serverRetryRunnable, wait) + return + } + serverRetryMs = SERVER_RETRY_MS // open: a later failure starts its backoff from scratch + // Publishing the server and claiming the held profile must be ONE step, under the same lock build() + // uses. As two independent volatiles they interleave: build() reads server==null on a binder thread, + // we publish and find pendingProfile still null, then build() stores it — and nobody ever replays it, + // leaving an open GATT server with no services that can never advertise. + val replay = synchronized(serverLock) { server = srv; pendingProfile.also { pendingProfile = null } } renameAdapter() + replay?.let { FileLog.event("mirror server opened — building the profile we held"); build(it) } } + private val serverRetryRunnable = Runnable { openServer() } + /** Guards the server/pendingProfile handover only — never held across a GATT call. */ + private val serverLock = Any() + @Volatile private var serverRetryMs = SERVER_RETRY_MS + @Volatile private var stopped = false + /** A profile handed to [build] before the server existed, replayed once it does. */ + @Volatile private var pendingProfile: GattProfile? = null + @Volatile private var latestProfile: GattProfile? = null + /** Rename the adapter to our advertised name, persisting the ORIGINAL to prefs so a process kill (which * skips stop()) doesn't lose the user's real Bluetooth name — and so we never capture our own rename. */ private fun renameAdapter() { @@ -174,7 +277,11 @@ class MirrorServer( * services + characteristics (re-adding them would strand apps still subscribed to the old instances * and there is no clean live rebuild). */ fun build(profile: GattProfile) { - val srv = server ?: return + latestProfile = profile + // No server yet (it is being retried): hold the profile rather than drop it, or a server that opens + // on the second attempt would have no services and would therefore never advertise. Under the same + // lock openServer() claims it with, so the read and the store cannot straddle the handover. + val srv = synchronized(serverLock) { server ?: run { pendingProfile = profile; null } } ?: return // Atomic gate: build() is called from both the GATT binder thread (onServicesDiscovered) and the main // thread (Start) — a plain check-then-set could let both through and double-add the services. if (!built.compareAndSet(false, true)) return @@ -185,7 +292,7 @@ class MirrorServer( // subscribers/clients too: clearServices() moves every ATT handle, so a peer that reconnected to a // remembered MAC would be tracked as subscribed to characteristic objects that no longer exist. // serviceRetries, or a rebuild starts with the budget the failed build already spent. - chars.clear(); pendingServices.clear(); subscribers.clear(); serviceRetries = 0 + chars.clear(); pendingServices.clear(); subscribers.clear(); serviceRetries = 0; audienceWarned.clear() for (svc in profile.services) { if (GattUuids.isStackService(svc.uuid)) continue val service = BluetoothGattService(svc.uuid, @@ -231,12 +338,26 @@ class MirrorServer( /** PEEK, don't poll: the service stays at the head until its own onServiceAdded confirms it. Removing it * up front let a late success (the stack had queued the "refused" add after all) and the retry both * drive the chain — adding a service twice and letting `servicesReady` fire with an add still in flight. */ - private fun addNextService() { + @Synchronized private fun addNextService() { + if (serviceAddOwner.current != null) return val svc = pendingServices.peek() ?: return - if (runCatching { server?.addService(svc) }.getOrNull() != true) { + // Claim ownership BEFORE the binder call: onServiceAdded can arrive on a binder thread before a + // post-call assignment lands, and a callback that finds no owner is discarded as stale — costing an + // 8 s watchdog and a whole server rebuild for an add that actually succeeded. + val watchdog = Runnable { + if (serviceAddOwner.clearIfCurrent(svc) { serviceAddWatchdog = null }) + rebuildServer("addService callback timeout for ${shortUuid(svc.uuid)}") + } + serviceAddWatchdog = watchdog + handler.postDelayed(watchdog, SERVICE_ADD_TIMEOUT_MS) + serviceAddOwner.replace(svc) + val accepted = runCatching { server?.addService(svc) }.getOrNull() == true + // Retract the claim only if the callback has not already consumed it (it may have completed the + // add while the binder call was still returning). + if (!accepted && serviceAddOwner.clearIfCurrent(svc) { serviceAddWatchdog = null }) { + handler.removeCallbacks(watchdog) if (serviceRetries++ >= SERVICE_MAX_RETRIES) { - FileLog.event("mirror addService REFUSED for ${shortUuid(svc.uuid)} — giving up, releasing build latch") - built.set(false) // so the next discovery can rebuild instead of staying silent forever + rebuildServer("addService refused for ${shortUuid(svc.uuid)}") return } FileLog.event("mirror addService REFUSED for ${shortUuid(svc.uuid)} — retry ${serviceRetries}") @@ -244,25 +365,63 @@ class MirrorServer( } } + private fun rebuildServer(reason: String) { + if (stopped) return + val wait = serviceRebuildMs + serviceRebuildMs = (wait * 2).coerceAtMost(SERVICE_REBUILD_MAX_MS) + FileLog.event("mirror service build failed: $reason — reopening in ${wait}ms") + servicesReady = false + built.set(false) + serviceAddOwner.clear() + serviceAddWatchdog?.let { handler.removeCallbacks(it) } + serviceAddWatchdog = null + handler.removeCallbacks(serviceRetryRunnable) + pendingServices.clear() + chars.clear() + // Closing the server invalidates every ATT handle and delivers NO disconnect callbacks, so any + // controller identity kept here would strand FTMS ownership on a generation that can never return: + // the app reconnects, gets a new generation, and is refused CONTROL_NOT_PERMITTED for the ride. + procedureDeadline?.let { handler.removeCallbacks(it.second) } + procedureDeadline = null + ftmsControl.clear() + terminalIndication = null + audienceWarned.clear() + clients.clear(); subscribers.clear() + // ...and never keep broadcasting under the trainer's name with no server behind it: an app that + // connects during the rebuild window finds no services and caches a broken device for the session. + stopAdvertising() + val failedServer = synchronized(serverLock) { + server.also { + server = null + pendingProfile = latestProfile + } + } + runCatching { failedServer?.close() } + onAdvState(false) + handler.removeCallbacks(serverRetryRunnable) + handler.postDelayed(serverRetryRunnable, wait) + } + fun stop() { // Stop the advertiser UNCONDITIONALLY: the `advertising` flag is transiently false mid-restart, so // trusting it here can leave the phone broadcasting with a closed GATT server. - advertising = false; servicesReady = false + stopped = true; pendingProfile = null; latestProfile = null; servicesReady = false + serviceAddOwner.clear() + serviceAddWatchdog?.let { handler.removeCallbacks(it) } + serviceAddWatchdog = null + ftmsControl.clear() + terminalIndication = null + audienceWarned.clear() + procedureDeadline?.let { handler.removeCallbacks(it.second) } + procedureDeadline = null + stopAdvertising() handler.removeCallbacksAndMessages(null) // pending adv starts / service retries must not outlive us - runCatching { adapter.bluetoothLeAdvertiser?.stopAdvertising(advCallback) } - if (advStarting) { - // The stop we just issued is dropped when a start is still in flight. Try once more after it - // has had time to complete — on a Handler that stop() has NOT just drained. - val cb = advCallback; val adv = adapter.bluetoothLeAdvertiser - Handler(Looper.getMainLooper()).postDelayed({ runCatching { adv?.stopAdvertising(cb) } }, ADV_LATE_STOP_MS) - } - advStarting = false runCatching { server?.close() } server = null restoreName() built.set(false); advBlueprint = null chars.clear(); cache.clear(); subscribers.clear(); clients.clear(); pendingServices.clear() - shownZycleLevel = null; lastRawZycleLevel = null; lastControlWriteMs = 0L; servoStepOwed = false + shownZycleLevel = null; lastRawZycleLevel = null; lastControlWriteMs = 0L; servoStepOwed = false; reanchorLevel = false } /** @@ -283,9 +442,121 @@ class MirrorServer( @Volatile private var lastRawZycleLevel: Int? = null // what the trainer last reported, to difference against @Volatile private var lastControlWriteMs = 0L // elapsedRealtime of the last control write we relayed @Volatile private var servoStepOwed = false // that write has a level step coming; it is not the rider's + /** The trainer link dropped, so the next level we see must be RE-ANCHORED rather than differenced. + * A drop does not stop the mirror (the GATT and the connected apps are deliberately kept), so without + * this the pair above straddles the outage and the first frame back is differenced against a level from + * before it — delivering the whole gap to the app in one step, as if the rider had made it. */ + @Volatile private var reanchorLevel = false + + /** For the service's periodic snapshot: how many apps are attached, and how far the level we report has + * drifted from the machine's (shown/raw — they diverge by every servo step we absorbed, by design). */ + /** UUIDs we have already reported as having no listener, so the notice is one line per dry spell and + * not one per 4 Hz packet. Cleared as soon as somebody subscribes. */ + private val audienceWarned = java.util.Collections.newSetFromMap(ConcurrentHashMap()) + + /** A value arrived from the trainer and there was nobody to hand it to. Silence here reads exactly like + * "the trainer never sent it", which is the wrong conclusion to draw from a log. */ + private fun noAudience(charUuid: UUID) { + // Only for characteristics that CAN have an audience. A read-only one (Feature, ranges, device + // info) is cached for a later read, not dropped — warning about it fires on every mirror start, + // when startEmit seeds the cache with every value we already read from the trainer. + val notifies = chars[charUuid]?.properties?.and( + BluetoothGattCharacteristic.PROPERTY_NOTIFY or BluetoothGattCharacteristic.PROPERTY_INDICATE) ?: 0 + if (notifies == 0) return + if (FileLog.enabled && audienceWarned.add(charUuid)) + FileLog.event("relay ${shortUuid(charUuid)} DROPPED — no app subscribed to it") + } + + val clientCount: Int get() = clients.size + val levelDebug: String get() = "${shownZycleLevel ?: "-"}/${lastRawZycleLevel ?: "-"}" + + /** Non-null once admitted: hand the same token back so a late failure cannot kill a newer procedure. + * The bytes travel WITH the procedure — a side slot let one procedure's response commit another's + * target, and left the local button with no payload at all. */ + internal fun admitLocalControl(opcode: Int, bytes: ByteArray): FtmsControlCoordinator.Procedure? = + ftmsControl.admitLocal(opcode, bytes)?.also { + FileLog.event("ftms ADMITTED local op=0x%02X #%d".format(opcode, it.id)) + } + internal fun localControlTransportFailed(procedure: FtmsControlCoordinator.Procedure) { + // Only the procedure that was actually still pending may cancel its deadline: a stale failure + // arriving after a newer procedure was admitted must not disarm the newer one's timer. + if (ftmsControl.transportFailed(procedure) != null) cancelProcedureDeadline(procedure) + } + /** The trainer took the write. Only now does the response clock start — arming at admission also + * measured our own serialised op queue, so a slow predecessor could expire a healthy procedure. */ + internal fun localControlDispatched(procedure: FtmsControlCoordinator.Procedure) = + armProcedureDeadline(procedure) + + fun releaseFtmsQuarantine() { + ftmsControl.trainerReady() + FileLog.event("ftms quarantine released") + } + + private fun armProcedureDeadline(procedure: FtmsControlCoordinator.Procedure) { + handler.post { + // An arm can reach main AFTER its own procedure ended and a newer one was armed — the local + // button path crosses two main-loop hops, so it loses that race routinely. Replacing the live + // deadline here would strip a healthy procedure of its only timer and leave it unbounded. + if (!ftmsControl.isPending(procedure)) return@post + procedureDeadline?.let { handler.removeCallbacks(it.second) } + val deadline = Runnable { + procedureDeadline = null + // A null return means "not the pending procedure" — the ONLY case that may skip recovery. + // A matched LOCAL procedure legitimately has no client, and skipping recovery for it left + // the session quarantined with nothing able to lift it for the rest of the ride. + val terminated = ftmsControl.timedOut(procedure) ?: return@Runnable + FileLog.event("ftms TIMEOUT op=0x%02X #%d — no trainer response in ${PROCEDURE_TIMEOUT_MS}ms" + .format(procedure.opcode, procedure.id)) + terminated.client?.let { + notifyControlResult(it, byteArrayOf( + 0x80.toByte(), procedure.opcode.toByte(), + FtmsControlCoordinator.OPERATION_FAILED.toByte())) + } + // a late opcode-only response can no longer be matched to a request: recycle the link + handler.post(onTrainerRecycle) + } + procedureDeadline = procedure to deadline + handler.postDelayed(deadline, PROCEDURE_TIMEOUT_MS) + } + } + + /** Cancels ONLY this procedure's deadline. Arming and cancelling are both posted from binder threads, + * so "cancel whatever is current" could disarm the timer of a procedure admitted in between. */ + private fun cancelProcedureDeadline(procedure: FtmsControlCoordinator.Procedure) { + handler.post { + val live = procedureDeadline ?: return@post + if (live.first.id != procedure.id) return@post + handler.removeCallbacks(live.second) + procedureDeadline = null + } + } + + /** The trainer's verdict. Only SUCCESS commits UI/servo/ERG state, and it commits the bytes THAT + * procedure carried — including the local button's, which must reach ErgBias so an armed ERG target + * is retired when the rider takes manual control. */ + private fun onControlOutcome(terminated: FtmsControlCoordinator.Terminated, accepted: Boolean) { + if (!accepted) return + lastControlWriteMs = SystemClock.elapsedRealtime() + servoStepOwed = true + terminated.bytes?.let(onControlAccepted) + } /** A value arrived from the trainer: correct power, cache, and notify every subscribed client. */ fun onZycleValue(charUuid: UUID, value: ByteArray) { + if (charUuid == GattUuids.FTMS_CONTROL_POINT && value.size >= 3 && + value[0].toInt() and 0xFF == 0x80) { + val opcode = value[1].toInt() and 0xFF + val result = value[2].toInt() and 0xFF + ftmsControl.response(opcode, result)?.let { terminated -> + cancelProcedureDeadline(terminated.procedure) + FileLog.event("ftms RESPONSE op=0x%02X result=0x%02X #%d -> %s".format(opcode, result, + terminated.procedure.id, + terminated.client?.let { "${it.address}#${it.generation}" } ?: "local")) + terminated.client?.let { notifyControlResult(it, value) } + onControlOutcome(terminated, result == FtmsControlCoordinator.SUCCESS) + } + return + } val out = when { charUuid == GattUuids.INDOOR_BIKE_DATA -> PowerRewrite.correctIndoorBikeData(value, correction()) charUuid == GattUuids.CYCLING_POWER_MEASUREMENT -> PowerRewrite.correctCyclingPower(value, correction()) @@ -296,20 +567,50 @@ class MirrorServer( // one bridge must never hand one app two different numbers for the same instant. charUuid == GattUuids.ZYCLE_TELEMETRY -> { PowerRewrite.zycleLevel(value)?.let { raw -> + // First frame after a dropout: re-anchor onto whatever the trainer says now, so the gap it + // moved through while we were blind is NOT differenced into the app's view. Deliberately + // NOT by nulling shownZycleLevel — levelToShow's first-frame rule adopts the raw level, + // which is the same jump by another route. A genuine press made during the outage is lost; + // we could not have seen it. + // ponytail: the flag has no expiry, so a press landing between the link coming back and + // the first telemetry frame is absorbed into the anchor too. That window is one frame + // (~250 ms at 4 Hz); bounding it with a timer would cost state and re-open the far worse + // jump this exists to stop. Revisit only if a trainer is seen going quiet after reconnect. + val reanchored = reanchorLevel + if (reanchorLevel) { lastRawZycleLevel = raw; reanchorLevel = false } + val prevRaw = lastRawZycleLevel; val prevShown = shownZycleLevel // The budget expires: 57 of 169 writes moved no level at all, and an armed one left // lying around would eat the rider's next press minutes later. val owed = servoStepOwed && SystemClock.elapsedRealtime() - lastControlWriteMs < LEVEL_SETTLE_MS val next = PowerRewrite.levelToShow(shownZycleLevel, lastRawZycleLevel, raw, owed) shownZycleLevel = next.level; servoStepOwed = next.servoStepOwed; lastRawZycleLevel = raw + // THE line that makes the servo-vs-rider rule auditable. Every claim in this file's + // comments ("118 of 125", "111 of 169 writes → 1 step") came from reconstructing this by + // hand out of hex dumps; logged directly, a ride answers it by counting lines. Only when + // the level actually moved or we re-anchored — a few hundred lines a ride, not 4 Hz. + if (FileLog.enabled && (reanchored || raw != prevRaw)) + FileLog.event("level raw=$prevRaw->$raw shown=$prevShown->${next.level} " + + (if (reanchored) "REANCHOR" else if (owed) "SERVO(spent)" else "RIDER") + + " owedAfter=${next.servoStepOwed}") } PowerRewrite.correctZycleTelemetry(value, correction(), shownZycleLevel) } else -> value } cache[charUuid] = out + // Machine Status is how FTMS ANNOUNCES a change the app did not command — the resistance knob was + // turned, the target moved. It fires only on a change, so log every one with its audience: "the + // trainer told us, and we had nobody to tell" is otherwise indistinguishable from "it never told us". + if (charUuid == GattUuids.MACHINE_STATUS && FileLog.enabled) { + val op = value.firstOrNull()?.toInt()?.and(0xFF) + val param = if (value.size > 1) FileLog.hex(value.copyOfRange(1, value.size)) else "-" + FileLog.event("machine status op=%s param=%s -> %d subscriber(s)" + .format(op?.let { "0x%02X".format(it) } ?: "-", param, subscribers[charUuid]?.size ?: 0)) + } val ch = chars[charUuid] ?: return - val subs = subscribers[charUuid] ?: return - if (subs.isEmpty()) return + val subs = subscribers[charUuid] ?: return noAudience(charUuid) + if (subs.isEmpty()) return noAudience(charUuid) + audienceWarned.remove(charUuid) logRelay(charUuid, value, out, subs.size) handler.post { val srv = server ?: return@post @@ -323,8 +624,8 @@ class MirrorServer( } @Suppress("DEPRECATION") - private fun notify(srv: BluetoothGattServer, dev: BluetoothDevice, ch: BluetoothGattCharacteristic, value: ByteArray, indicate: Boolean) { - runCatching { + private fun notify(srv: BluetoothGattServer, dev: BluetoothDevice, ch: BluetoothGattCharacteristic, value: ByteArray, indicate: Boolean): Boolean { + return runCatching { val ok = if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.TIRAMISU) srv.notifyCharacteristicChanged(dev, ch, indicate, value) == android.bluetooth.BluetoothStatusCodes.SUCCESS else { @@ -334,17 +635,77 @@ class MirrorServer( } // a refused notification is a silently dropped sample — "power froze in the app" if (!ok) FileLog.event("notify ${shortUuid(ch.uuid)} REFUSED (buffer full?) -> ${dev.address}") + ok + }.getOrDefault(false) + } + + /** The origin is GONE or the stack refused the indication outright: it will never see the terminal + * result, so drop its claim or it keeps ERG locked for everyone. + * A rejection is not terminal for an admitted procedure and carries no such authority — a stale one + * could otherwise revoke ownership the same client legitimately acquired in the meantime. */ + private fun undeliverable(client: FtmsControlCoordinator.Client, why: String, terminal: Boolean) { + if (!terminal || !ftmsControl.owns(client)) return + if (ftmsControl.releaseOwner(client)) + FileLog.event("ftms terminal result undeliverable ($why) -> ${client.address}#${client.generation} — owner released") + } + + /** NOT the same thing: the client is still connected and can still drive the trainer, it just has no + * CCCD on the Control Point yet. Real controllers (Bestcycling) send Request Control BEFORE they + * subscribe, so revoking ownership here refused every command they sent afterwards — a lost + * indication turned into no ERG at all. Log it and leave the claim standing. */ + private fun undelivered(client: FtmsControlCoordinator.Client, why: String) { + FileLog.event("ftms result not delivered ($why) -> ${client.address}#${client.generation} — control kept") + } + + private fun notifyControlResult( + client: FtmsControlCoordinator.Client, + value: ByteArray, + terminal: Boolean = true, + ) { + val uuid = GattUuids.FTMS_CONTROL_POINT + val ch = chars[uuid] ?: return undeliverable(client, "no local characteristic", terminal) + val subs = subscribers[uuid] ?: return undelivered(client, "nobody subscribed to 0x2AD9 yet") + if (ftmsControl.identity(client.address) != client) return undeliverable(client, "stale generation", terminal) + if (!synchronized(subs) { subs.contains(client.address) }) return undelivered(client, "not subscribed yet") + handler.post { + val srv = server ?: return@post undeliverable(client, "server closed", terminal) + if (ftmsControl.identity(client.address) != client) return@post undeliverable(client, "stale generation", terminal) + val dev = clients[client.address] ?: return@post undeliverable(client, "device gone", terminal) + val currentSubs = subscribers[uuid] ?: return@post undelivered(client, "nobody subscribed to 0x2AD9 yet") + if (!synchronized(currentSubs) { currentSubs.contains(client.address) }) + return@post undelivered(client, "unsubscribed before send") + if (terminal) terminalIndication = client + if (!notify(srv, dev, ch, value, ch.properties and BluetoothGattCharacteristic.PROPERTY_INDICATE != 0)) { + terminalIndication = null + // The controller would wait forever for a response it will never get. Drop its claim and cut + // the link so it reconnects and re-arbitrates instead of sitting there believing it owns ERG. + undeliverable(client, "indication refused", terminal) + cancelClient(client) + } } } + private fun cancelClient(client: FtmsControlCoordinator.Client) { + if (ftmsControl.identity(client.address) != client) return + clients[client.address]?.let { server?.cancelConnection(it) } + } + private val serverCallback = object : BluetoothGattServerCallback() { - override fun onServiceAdded(status: Int, service: BluetoothGattService?) { + @Synchronized override fun onServiceAdded(status: Int, service: BluetoothGattService?) { + val added = service ?: return + if (!serviceAddOwner.clearIfCurrent(added) { + serviceAddWatchdog?.let { handler.removeCallbacks(it) } + serviceAddWatchdog = null + }) return + // A callback still in flight when stop() ran would otherwise find pendingServices empty, set + // servicesReady and post a start — putting us back on the air with a closed GATT server. + if (stopped || server == null) return if (status != BluetoothGatt.GATT_SUCCESS) { // don't poll it: retry the head rather than advertise a mirror missing a service - FileLog.event("mirror addService FAILED status=$status for ${shortUuid(service?.uuid)} — retrying head") + FileLog.event("mirror addService FAILED status=$status for ${shortUuid(added.uuid)} — retrying head") if (serviceRetries++ < SERVICE_MAX_RETRIES) { handler.removeCallbacks(serviceRetryRunnable); handler.postDelayed(serviceRetryRunnable, SERVICE_RETRY_MS) - } else { FileLog.event("mirror giving up on ${shortUuid(service?.uuid)} — releasing build latch"); built.set(false) } + } else rebuildServer("addService callback status=$status for ${shortUuid(added.uuid)}") return } handler.removeCallbacks(serviceRetryRunnable) // a stale retry would add the NEXT service twice @@ -352,6 +713,7 @@ class MirrorServer( serviceRetries = 0 if (pendingServices.isEmpty()) { // the mirrored GATT is complete servicesReady = true + serviceRebuildMs = SERVICE_REBUILD_MS handler.post { startAdvertising() } } else addNextService() } @@ -363,15 +725,21 @@ class MirrorServer( return } if (newState == android.bluetooth.BluetoothProfile.STATE_CONNECTED) { - clients[device.address] = device; onStatus(context.getString(R.string.status_app_connected, clients.size)) + ftmsControl.connected(device.address) + clients[device.address] = device + onStatus(context.getString(R.string.status_app_connected, clients.size)) FileLog.event("app connected ${device.address} status=$status (${clients.size} total)") // Android stops connectable advertising once a central connects — restart it so a SECOND // central (e.g. the Garmin) can still discover us. handler.post { restartAdvertising() } } else { + val lostPending = ftmsControl.disconnected(device.address)?.also { + cancelProcedureDeadline(it.procedure) + } != null clients.remove(device.address); subscribers.values.forEach { it.remove(device.address) } onStatus(context.getString(R.string.status_app_disconnected, clients.size)) FileLog.event("app disconnected ${device.address} status=$status (${clients.size} left)") + if (lostPending) handler.post(onTrainerRecycle) handler.post { restartAdvertising() } // the controller stopped our advert when it connected } } @@ -399,14 +767,25 @@ class MirrorServer( override fun onCharacteristicWriteRequest(device: BluetoothDevice?, requestId: Int, ch: BluetoothGattCharacteristic?, preparedWrite: Boolean, responseNeeded: Boolean, offset: Int, value: ByteArray?) { val uuid = ch?.uuid + if (preparedWrite && uuid == GattUuids.FTMS_CONTROL_POINT) { + FileLog.event("app write ${shortUuid(uuid)} <- ${device?.address} PREPARED rejected") + if (responseNeeded) runCatching { + server?.sendResponse(device, requestId, ATT_REQUEST_NOT_SUPPORTED, offset, null) + } + return + } + if (uuid == GattUuids.FTMS_CONTROL_POINT && value?.isEmpty() == true) { + FileLog.event("app write ${shortUuid(uuid)} <- ${device?.address} empty rejected") + if (responseNeeded) runCatching { + server?.sendResponse(device, requestId, ATT_INVALID_ATTRIBUTE_VALUE_LENGTH, offset, null) + } + return + } var relayed = false val tag = "${shortUuid(uuid)} <- ${device?.address}" + (if (preparedWrite) " PREPARED off=$offset" else "") + (if (!responseNeeded) " noResp" else "") if (uuid != null && value != null) { val out = if (GattUuids.carriesControl(uuid)) PowerRewrite.inverseTargetPower(value, correction()) else value - // Any control op can make the servo move the level; from here on that move is ours, not the - // rider's. Stamped before the relay, so the window covers the trip to the trainer too. - if (GattUuids.carriesControl(uuid)) { lastControlWriteMs = SystemClock.elapsedRealtime(); servoStepOwed = true } // what the client asked for, unless the trainer's characteristic can't take a Write Command val withResponse = responseNeeded || (ch.properties and BluetoothGattCharacteristic.PROPERTY_WRITE_NO_RESPONSE == 0) @@ -414,27 +793,65 @@ class MirrorServer( // ponytail: a prepared (long) write is relayed fragment-by-fragment rather than buffered // until onExecuteWrite. No FTMS/CPS characteristic exceeds one ATT payload, so this only // matters if some app starts using long writes — the log line above says when it happens. - relayed = toZycle(uuid, out, withResponse) // relay to the trainer + if (!preparedWrite && uuid == GattUuids.FTMS_CONTROL_POINT && device != null && value.isNotEmpty()) { + val opcode = value[0].toInt() and 0xFF + when (val admission = ftmsControl.admit(device.address, opcode, out)) { + // No live identity: fail CLOSED. Minting one here from `clients` — which is cleared + // a few instructions after the coordinator on disconnect and on rebuild — would let + // a departing app be resurrected and promoted to owner, which is the exact hole the + // by-address admission was written to close. + null -> FileLog.event("ftms REJECTED op=0x%02X — no live connection <- %s" + .format(opcode, device.address)) + is FtmsControlCoordinator.Admission.Rejected -> { + FileLog.event("ftms REJECTED op=0x%02X result=0x%02X <- %s" + .format(opcode, admission.result, device.address)) + admission.client?.let { + notifyControlResult(it, + byteArrayOf(0x80.toByte(), opcode.toByte(), admission.result.toByte()), + terminal = false) + } + } + is FtmsControlCoordinator.Admission.Admitted -> { + val procedure = admission.procedure + FileLog.event("ftms ADMITTED op=0x%02X #%d <- %s#%d" + .format(opcode, procedure.id, device.address, procedure.client?.generation ?: 0L)) + relayed = toZycle(uuid, out, withResponse) { success -> + // Transport success is NOT command success: FTMS puts acceptance in the + // Response Code, so nothing commits until onZycleValue sees it. The response + // clock starts HERE, once the machine actually has the write. + if (success) armProcedureDeadline(procedure) + else ftmsControl.transportFailed(procedure)?.let { + cancelProcedureDeadline(procedure) + it.client?.let { c -> + notifyControlResult(c, byteArrayOf( + 0x80.toByte(), procedure.opcode.toByte(), + FtmsControlCoordinator.OPERATION_FAILED.toByte(), + )) + } + } + } + if (!relayed) ftmsControl.transportFailed(procedure)?.let { + cancelProcedureDeadline(procedure) + it.client?.let { c -> + notifyControlResult(c, byteArrayOf( + 0x80.toByte(), procedure.opcode.toByte(), + FtmsControlCoordinator.OPERATION_FAILED.toByte())) + } + } + } + } + } else relayed = toZycle(uuid, out, withResponse) { success -> + if (success && GattUuids.carriesControl(uuid)) { + lastControlWriteMs = SystemClock.elapsedRealtime() + servoStepOwed = true + } + } if (!relayed) FileLog.event("app write $tag NOT RELAYED — answering failure") } else FileLog.event("app write $tag = ") // ATT response = "received", always. FTMS puts the OUTCOME in the control point indication. if (responseNeeded) runCatching { server?.sendResponse(device, requestId, BluetoothGatt.GATT_SUCCESS, offset, value) } - // ...and if we could not hand it to the trainer, say so the way a trainer would: Response Code - // 0x80, , 0x04 Operation Failed. Without this the app waits forever for an indication. - if (!relayed && uuid != null && device != null && value != null && value.isNotEmpty() && - !preparedWrite && GattUuids.carriesControl(uuid)) { - // ONLY to the client that wrote, and NOT into the read cache: the response belongs to one - // FTMS procedure, and fanning it out tells the other app its own request failed. - val resp = byteArrayOf(0x80.toByte(), value[0], 0x04) - val cp = ch - // only if this client actually enabled the control point — never indicate unsolicited - if (subscribers[uuid]?.contains(device.address) == true) handler.post { - val srv = server ?: return@post - notify(srv, device, cp, resp, cp.properties and BluetoothGattCharacteristic.PROPERTY_INDICATE != 0) - } - } } override fun onDescriptorWriteRequest(device: BluetoothDevice?, requestId: Int, descriptor: BluetoothGattDescriptor?, @@ -460,7 +877,18 @@ class MirrorServer( /** Notification flow control: a failure here means our notifications stopped reaching the app. */ override fun onNotificationSent(device: BluetoothDevice?, status: Int) { - if (status != BluetoothGatt.GATT_SUCCESS) FileLog.event("notify FAILED status=$status -> ${device?.address}") + if (status == BluetoothGatt.GATT_SUCCESS) return + FileLog.event("notify FAILED status=$status -> ${device?.address}") + // notifyCharacteristicChanged() returning success only means the send was accepted for + // dispatch; THIS is where Android reports whether it actually landed. If the send in flight + // was a terminal Control Point result, its origin will wait forever for an answer it will + // never see, while every other app is refused because it still holds control. + val addr = device?.address ?: return + val pendingTerminal = terminalIndication ?: return + if (pendingTerminal.address != addr) return + terminalIndication = null + undeliverable(pendingTerminal, "onNotificationSent status=$status", terminal = true) + cancelClient(pendingTerminal) } override fun onMtuChanged(device: BluetoothDevice?, mtu: Int) { @@ -481,32 +909,71 @@ class MirrorServer( } // ── advertising ────────────────────────────────────────────────────────────────────────────────── - private val advCallback = object : android.bluetooth.le.AdvertiseCallback() { - override fun onStartSuccess(settingsInEffect: AdvertiseSettings?) { handler.removeCallbacks(advStartWatchdog); advStarting = false; advertising = true; advRetries = 0; onAdvState(true); onStatus(context.getString(R.string.status_advertising, advertisedName)); FileLog.event("advertising as $advertisedName") - // a stop issued while this start was in flight is dropped by the stack — reconcile now - if (!trainerLinked || server == null) { FileLog.event("advertising with no trainer — stopping"); stopAdvertising() } - } - override fun onStartFailure(errorCode: Int) { - handler.removeCallbacks(advStartWatchdog); advStarting = false; advertising = false; onAdvState(false) - onStatus(context.getString(R.string.status_advertise_failed, errorCode)) - FileLog.event("advertise failed $errorCode (retry ${advRetries + 1}/$ADV_MAX_RETRIES, name=${!dropNameFromAdv})") - // 31-byte PDU: shed the cloned manufacturer data first (usually the culprit), the name only if - // that still isn't enough — apps find us BY the name, so it is the last thing to go. - if (errorCode == ADVERTISE_FAILED_DATA_TOO_LARGE) when { - !dropMfrFromAdv -> dropMfrFromAdv = true // the cloned manufacturer data usually is it - !dropBlueprintFromAdv -> dropBlueprintFromAdv = true // then the cloned UUIDs (128-bit won't fit) - else -> dropNameFromAdv = true // last resort: apps find us BY the name + private fun newAdvAttempt(advertiser: BluetoothLeAdvertiser): Pair { + lateinit var callback: AdvertiseCallback + lateinit var watchdog: Runnable + callback = object : AdvertiseCallback() { + override fun onStartSuccess(settingsInEffect: AdvertiseSettings?) { + handler.removeCallbacks(watchdog) + resolveAdvOrphan(this) // our one callback arrived: resolved, current or not + if (!advAttempts.runIfCurrent(this) { + advStarting = false; advertising = true; advRetries = 0; advRetryMs = ADV_RETRY_MS + onAdvState(true); onStatus(context.getString(R.string.status_advertising, advertisedName)) + FileLog.event("advertising as $advertisedName") + if (!trainerLinked || server == null) { + FileLog.event("advertising with no trainer — stopping") + stopAdvertising() + } + }) { + // Late success for a retired attempt: its registration is real, so stop it. Resolved + // above, so this stop can no longer be dropped by the stack. + runCatching { advertiser.stopAdvertising(this) } + } } - if (advRetries++ < ADV_MAX_RETRIES) { - handler.removeCallbacks(startAdvRunnable); handler.postDelayed(startAdvRunnable, ADV_RETRY_MS) + + override fun onStartFailure(errorCode: Int) { + handler.removeCallbacks(watchdog) + resolveAdvOrphan(this) // no registration exists for a failed start, orphaned or not + advAttempts.failIfCurrent( + this, + stop = { runCatching { advertiser.stopAdvertising(it) } }, + markFailed = { + if (lastAdvCallback === this) lastAdvCallback = null + advStarting = false; advertising = false; onAdvState(false) + onStatus(context.getString(R.string.status_advertise_failed, errorCode)) + FileLog.event("advertise failed $errorCode (attempt ${++advRetries}, name=${!dropNameFromAdv})") + if (errorCode == ADVERTISE_FAILED_DATA_TOO_LARGE) when { + !dropMfrFromAdv -> dropMfrFromAdv = true + !dropBlueprintFromAdv -> dropBlueprintFromAdv = true + else -> dropNameFromAdv = true + } + }, + retry = { scheduleAdvRetry("failure $errorCode") }, + ) } } + watchdog = Runnable { + advAttempts.retireIfCurrent( + callback, + // Unresolved by definition — that is what the watchdog fires on. One stop is not enough: + // if the start is still in flight the stack drops it, so hand it to the orphan sweep. + retire = { orphanAdvCallback(it) }, + after = { + advStarting = false; advertising = false; onAdvState(false) + FileLog.event("advertise start never answered — retiring attempt and retrying") + scheduleAdvRetry("start never answered") + }, + ) + } + return callback to watchdog } private fun startAdvertising() { // no trainer → stay off the air (see setTrainerLinked); not built → we'd advertise an empty GATT and // an app that connects in that window caches it. onServiceAdded calls back here once services land. - if (advertising || advStarting || !trainerLinked || !servicesReady) return + // `stopped`/`server` too: a callback still in flight when stop() ran must not put us back on the air + // with a closed GATT server behind the advert. + if (stopped || server == null || advertising || advStarting || !trainerLinked || !servicesReady) return val advertiser = adapter.bluetoothLeAdvertiser ?: run { onStatus(context.getString(R.string.status_ble_adv_unsupported)); onAdvState(false); return } val settings = AdvertiseSettings.Builder() .setAdvertiseMode(AdvertiseSettings.ADVERTISE_MODE_LOW_LATENCY) @@ -525,13 +992,32 @@ class MirrorServer( .addServiceUuid(ParcelUuid(GattUuids.uuid16(0x1826))) } advStarting = true - lastAdvCallback = advCallback // process-wide, so a later instance can still stop this set - if (runCatching { advertiser.startAdvertising(settings, builder.build(), advCallback) }.isFailure) advStarting = false - else { + // One callback is one controller registration. Retire any orphan before publishing the new owner. + val (callback, watchdog) = newAdvAttempt(advertiser) + // A previous owner still here means its start never resolved (a resolved one is retired by its own + // callback), so it is an orphan, not a plain stop. + advAttempts.begin(callback) { old -> orphanAdvCallback(old) } + lastAdvCallback = callback // process-wide, so a later instance can still stop this set + lastAdvUnresolved = true // ...and know whether that stop can be dropped by the stack + if (runCatching { advertiser.startAdvertising(settings, builder.build(), callback) }.isFailure) { + // A synchronous throw answers with no callback at all, so this is the only place that can report + // it. Clearing the flag alone left health green and nothing scheduled. + advAttempts.failIfCurrent( + callback, + // The start was never accepted, so there is no registration to chase: a plain stop, and + // deliberately NOT an orphan — an entry nothing can ever resolve would be swept forever. + stop = { runCatching { advertiser.stopAdvertising(it) } }, + markFailed = { + if (lastAdvCallback === callback) lastAdvCallback = null + advStarting = false; advertising = false; onAdvState(false) + }, + retry = { scheduleAdvRetry("start threw") }, + ) + } else { // An accepted start normally answers with exactly one callback — except when the adapter is // turned off or the BT process dies under it, which drops the callback silently. Without this // the flag latches and we never advertise again. - handler.removeCallbacks(advStartWatchdog); handler.postDelayed(advStartWatchdog, ADV_START_TIMEOUT_MS) + handler.postDelayed(watchdog, ADV_START_TIMEOUT_MS) } } @@ -539,20 +1025,86 @@ class MirrorServer( * onStartSuccess, so an early return here can leave a pending advert running with no trainer behind it. */ private fun stopAdvertising() { handler.removeCallbacks(startAdvRunnable) - advertising = false - // NOT advStarting: a stop issued while a start is in flight is dropped by the stack, so the start - // is still coming. Only its callback may clear the flag, or we let a second start through. - runCatching { adapter.bluetoothLeAdvertiser?.stopAdvertising(advCallback) } + val wasStarting = advStarting + // Clear waits for a callback already admitted by runIfCurrent; finalize flags only after it exits. + val callback = advAttempts.clear() + // advStarting IS cleared here now, unlike before. A stop issued while a start is in flight is dropped + // by the stack, so that start is still coming and a second one can get through — but it now builds a + // NEW callback, i.e. a separate registration, while this one is retired from the owner (its late + // callback is rejected) and handed to the orphan sweep, which keeps stopping it until its own + // callback arrives. So the extra registration is chased until it is provably gone, rather than + // stopped once on a delay that no Android contract actually bounds. + advertising = false; advStarting = false + callback ?: return + // Only an UNRESOLVED start needs the sweep: its stop can be dropped and nothing else holds the + // handle. A resolved attempt is stopped once, reliably, right here. + if (wasStarting) orphanAdvCallback(callback) + else { + if (lastAdvCallback === callback) lastAdvCallback = null + runCatching { adapter.bluetoothLeAdvertiser?.stopAdvertising(callback) } + } + } + + /** Retire a callback whose start never resolved: stop it now, and keep stopping it until its own + * callback proves the registration is gone. [resolved] callbacks skip this — their result is known. */ + private fun orphanAdvCallback(cb: AdvertiseCallback) { + advOrphans.add(cb) + if (lastAdvCallback === cb) lastAdvCallback = null + runCatching { adapter.bluetoothLeAdvertiser?.stopAdvertising(cb) } + advSweepMs = ADV_SWEEP_MS + orphanHandler.removeCallbacks(advSweep); orphanHandler.postDelayed(advSweep, advSweepMs) + } + + /** An orphan's own callback finally arrived: that is the only proof the registration resolved. Also + * the one place that can mark the process-wide handle resolved, for a later instance's handoff. */ + private fun resolveAdvOrphan(cb: AdvertiseCallback) { + advOrphans.remove(cb) + if (lastAdvCallback === cb) lastAdvUnresolved = false + } + + private var advSweepMs = ADV_SWEEP_MS + private val advSweep = object : Runnable { + override fun run() { + val advertiser = adapter.bluetoothLeAdvertiser + if (advertiser == null) { // adapter off: every prior registration died with it + if (advOrphans.isNotEmpty()) FileLog.event("adapter off — dropping ${advOrphans.size} orphan advertising set(s)") + advOrphans.clear(); advSweepMs = ADV_SWEEP_MS + return + } + val current = advAttempts.current + // Snapshot under the lock, call the advertiser outside it. NEVER the current attempt. + val targets = synchronized(advOrphans) { advOrphans.toList() }.filter { it !== current } + for (cb in targets) runCatching { advertiser.stopAdvertising(cb) } + if (advOrphans.isEmpty()) { advSweepMs = ADV_SWEEP_MS; return } + advSweepMs = (advSweepMs * 2).coerceAtMost(ADV_SWEEP_MAX_MS) + orphanHandler.postDelayed(this, advSweepMs) + } } /** Force a fresh advertise (Android silently stopped it when a central connected, but our flag didn't * know). Needed so more than one app can find us. */ private val startAdvRunnable = Runnable { startAdvertising() } - private val advStartWatchdog = Runnable { - if (advStarting) { FileLog.event("advertise start never answered — clearing in-flight flag"); advStarting = false } + /** + * The one place that re-arms advertising. A capped ATTEMPT COUNT was the bug this replaces: five + * transient failures took the mirror off the air for the whole ride. A flat 1 s retry is the opposite + * mistake — a revoked BLUETOOTH_ADVERTISE or a stack that throws every time would retry ~3600 times an + * hour, each one a log line, across a 4-12 h ride. So: backoff, no cap. The budget resets on a real + * success and when the trainer link comes back. + * + * Each attempt owns a distinct callback. Its watchdog retires that registration before scheduling the + * retry, so callbacks from an old attempt cannot cancel or mutate the current one. + */ + private fun scheduleAdvRetry(why: String) { + if (stopped) return + val wait = advRetryMs + advRetryMs = (wait * 2).coerceAtMost(ADV_RETRY_MAX_MS) + FileLog.event("advertise retry in ${wait}ms: $why") + handler.removeCallbacks(startAdvRunnable); handler.postDelayed(startAdvRunnable, wait) } private fun restartAdvertising() { + // an app connecting/disconnecting is a fresh chance, not a continuation of old failures + advRetries = 0; advRetryMs = ADV_RETRY_MS stopAdvertising() // The stop is async and only frees this callback when it completes; starting in the same turn // answers ADVERTISE_FAILED_ALREADY_STARTED. Give it a turn — and collapse duplicate restarts @@ -573,7 +1125,34 @@ class MirrorServer( } private companion object { + /** + * Callbacks retired while their start was STILL UNRESOLVED — and only those. The callback IS the + * controller registration, and a stop issued while its start is in flight is dropped by the stack, + * so such an attempt can stay registered with nothing holding its handle: an advertiser slot burnt, + * or an obsolete mirror on the air, until Bluetooth restarts. Membership ends only when that + * attempt's OWN callback is finally delivered, because nothing else proves the registration is gone. + * + * Deliberately NOT every started attempt: a sweep must never stop the live one. An attempt whose + * result is already known (onStartFailure, a synchronous throw — the start was never accepted) is + * not an orphan either. + * + * Process-wide: an orphan has to outlive the MirrorServer that created it, which is the whole point. + * + * ponytail: stopAdvertising() does not confirm removal and a start can stay in flight past + * ADV_START_TIMEOUT_MS, so NO finite delay can guarantee the retirement lands. The sweep backs off + * to ADV_SWEEP_MAX_MS and keeps trying while the set is non-empty; a null advertiser (adapter off) + * is the one piece of evidence that every prior registration is definitively gone. + */ + private val advOrphans: MutableSet = + java.util.Collections.synchronizedSet(mutableSetOf()) + /** NOT the instance handler: stop() drains that one, and an orphan must outlive its mirror. */ + private val orphanHandler by lazy { Handler(Looper.getMainLooper()) } @Volatile private var lastAdvCallback: android.bluetooth.le.AdvertiseCallback? = null + /** Whether [lastAdvCallback]'s start is still UNRESOLVED. A bare reference cannot say: a callback + * that already got its onStartSuccess is registered but RESOLVED, so the next instance must stop it + * once — never adopt it as an orphan, which nothing could ever resolve and the sweep would chase + * every 30 s for the life of the process. */ + @Volatile private var lastAdvUnresolved = false const val KEY_ADV_NAMES = "advertisedNamesUsed" const val KEY_ORIG_NAME = "origBtName" } diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/ble/SimSource.kt b/app/src/main/java/com/enderthor/trainerbridgeble/ble/SimSource.kt index 010007b..fc0bb6f 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/ble/SimSource.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/ble/SimSource.kt @@ -108,9 +108,14 @@ class SimSource( override fun stop() { handler.removeCallbacks(ticker); onState(false); FileLog.event("SIM trainer stopped") } - override fun write(charUuid: UUID, bytes: ByteArray, withResponse: Boolean): Boolean { + override fun write( + charUuid: UUID, + bytes: ByteArray, + withResponse: Boolean, + onComplete: (Boolean) -> Unit, + ): Boolean { FileLog.event("SIM write ${bytes.joinToString("") { "%02X".format(it) }}") - if (charUuid != CONTROL || bytes.isEmpty()) return true + if (charUuid != CONTROL || bytes.isEmpty()) { onComplete(true); return true } val op = bytes[0].toInt() and 0xFF when (op) { 0x05 -> if (bytes.size >= 3) ergTarget = (bytes[1].toInt() and 0xFF) or ((bytes[2].toInt() and 0xFF) shl 8) // Set Target Power @@ -124,6 +129,7 @@ class SimSource( // down 0x13): answer "op code not supported" (0x02) for those instead of a success an app would // then wait on — a slope-mode app would otherwise watch power ignore the grade forever. val result: Byte = if (op in IMPLEMENTED_OPS) 0x01 else 0x02 + onComplete(true) onValue(CONTROL, byteArrayOf(0x80.toByte(), (op and 0xFF).toByte(), result)) return true } diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/ble/TrainerSource.kt b/app/src/main/java/com/enderthor/trainerbridgeble/ble/TrainerSource.kt index 4d6927b..d59c247 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/ble/TrainerSource.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/ble/TrainerSource.kt @@ -7,7 +7,17 @@ import java.util.UUID interface TrainerSource { fun start() fun stop() + /** True while a BLE scan is actually registered with the controller. The idle wakelock guard needs + * this: releasing the CPU is only safe once the controller is holding the search for us, because a + * postDelayed retry does NOT wake a suspended CPU — with no scan up, the trainer's advertising has + * nothing to arrive at. */ + val searching: Boolean get() = false /** @return false if the write could not be dispatched (no link, unknown characteristic) — the mirror * must NOT then answer the app with success. */ - fun write(charUuid: UUID, bytes: ByteArray, withResponse: Boolean): Boolean + fun write( + charUuid: UUID, + bytes: ByteArray, + withResponse: Boolean, + onComplete: (Boolean) -> Unit = {}, + ): Boolean } diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/ble/ZycleClient.kt b/app/src/main/java/com/enderthor/trainerbridgeble/ble/ZycleClient.kt index 6653478..47a58e8 100644 --- a/app/src/main/java/com/enderthor/trainerbridgeble/ble/ZycleClient.kt +++ b/app/src/main/java/com/enderthor/trainerbridgeble/ble/ZycleClient.kt @@ -16,9 +16,15 @@ import android.os.Handler import android.os.Looper import android.util.Log import com.enderthor.trainerbridgeble.FileLog +import com.enderthor.trainerbridgeble.FtmsBootstrapReadiness +import com.enderthor.trainerbridgeble.GattSessionCoordinator +import com.enderthor.trainerbridgeble.IdentityOwner +import com.enderthor.trainerbridgeble.TrainerWriteTicket import java.util.UUID +import java.util.concurrent.ConcurrentHashMap import java.util.concurrent.ConcurrentLinkedQueue import java.util.concurrent.atomic.AtomicBoolean +import java.util.concurrent.atomic.AtomicLong /** * BLE central to the trainer (Zycle). Scans filtered by FTMS/address, connects, discovers the FULL GATT, subscribes @@ -47,31 +53,71 @@ class ZycleClient( private val handler = Handler(Looper.getMainLooper()) private val adapter by lazy { (context.getSystemService(Context.BLUETOOTH_SERVICE) as BluetoothManager).adapter } - @Volatile private var gatt: BluetoothGatt? = null + private val gattSessions = GattSessionCoordinator( + resetRuntime = { + lastMessageMs = 0L + onState(false) + completePendingWrites(false) + opQueue.clear(); opBusy.set(false); syncOwed.set(false); burstEnqueued = false + bootstrapReadiness = null + connecting.set(false); inFlightWrite = null + }, + disconnect = { runCatching { it.disconnect() } }, + close = { runCatching { it.close() } }, + reconnect = { scheduleReconnect() }, + ) + private var gatt: BluetoothGatt? + get() = gattSessions.current + set(value) { gattSessions.replace(value) } + /** Owns the ONE connect attempt allowed to publish a handle. connectGatt() is a blocking Binder call and + * stop() can run to completion inside it, so a plain `stopped` check cannot gate the publication: the + * check would pass, stop() would find no GATT to close, and the attempt would then install an orphan + * that keeps the trainer to itself for the rest of the ride. Distinct from [connecting], which stops + * concurrent connectGatt() calls; this decides which attempt still OWNS the outcome. */ + private val connectAttempts = IdentityOwner() private val connecting = AtomicBoolean(false) // CAS: scan results arrive on a binder thread pool @Volatile private var stopped = false @Volatile private var scanning = false - @Volatile private var lastMessageMs = 0L // wall-clock of the last notification, for the silent-link watchdog + override val searching: Boolean get() = scanning + // elapsedRealtime, not wall-clock: a mid-ride clock re-sync would otherwise either trip the watchdog on + // a healthy link or delay it past a real one, by the size of the correction. + @Volatile private var lastMessageMs = 0L // last notification, for the silent-link watchdog private val reconnectPending = AtomicBoolean(false) @Volatile private var retryMs = SCAN_RETRY_MS // scan backoff, reset on a good connection + // Have we ever had this trainer on the line in THIS session? Splits the two scans that look alike: + // a cold search (trainer not powered on — may run for hours) from a mid-ride reacquisition. + @Volatile private var everConnected = false private val opQueue = ConcurrentLinkedQueue<() -> Unit>() private val opBusy = AtomicBoolean(false) private val syncOwed = AtomicBoolean(false) // onSynced not yet delivered for THIS connection @Volatile private var burstEnqueued = false // the opening read/subscribe burst is in the queue + @Volatile private var bootstrapReadiness: FtmsBootstrapReadiness? = null /** Deliver [onSynced] at most once per connection, on the main thread, and never for a link that has * dropped in the meantime: a stale delivery would put the mirror on the air with no trainer behind it, * and setTrainerLinked is edge-triggered, so it would STAY there. */ private fun fireSynced(g: BluetoothGatt) { - if (!syncOwed.compareAndSet(true, false)) return - handler.post { if (!stopped && gatt === g) onSynced() } + gattSessions.runIfCurrent(g) { + if (bootstrapReadiness?.ready != true) return@runIfCurrent + if (!syncOwed.compareAndSet(true, false)) return@runIfCurrent + handler.post { if (!stopped) gattSessions.runIfCurrent(g) { onSynced() } } + } } private val opToken = java.util.concurrent.atomic.AtomicInteger(0) // guards the per-op watchdog vs a stale timeout - private class WriteReq(val uuid: UUID, val bytes: ByteArray, val withResponse: Boolean, val retriesLeft: Int, val seq: Int) + private data class WriteReq( + val session: BluetoothGatt, + val characteristic: BluetoothGattCharacteristic, + val uuid: UUID, + val bytes: ByteArray, + val withResponse: Boolean, + val retriesLeft: Int, + val ticket: TrainerWriteTicket, + ) @Volatile private var inFlightWrite: WriteReq? = null // the write currently on the wire, for retry on failure - private val writeSeq = java.util.concurrent.atomic.AtomicInteger(0) // bumps per write; a retry is dropped if superseded + private val pendingWrites = ConcurrentHashMap.newKeySet() + private val writeSeq = AtomicLong(0) // bumps per write; a retry is dropped if superseded private val cccd: UUID = UUID.fromString("00002902-0000-1000-8000-00805f9b34fb") @@ -85,13 +131,20 @@ class ZycleClient( override fun stop() { stopped = true + // BEFORE clearing the GATT session: an in-flight connectGatt() then fails its ownership check and closes + // its own handle. Both paths cross this monitor, and this clear precedes the session clear below, so + // either the attempt published first (and the read closes it) or it never publishes at all. + connectAttempts.clear() connecting.set(false) + // Session ownership is the admission barrier: enqueueWrite either registers its ticket before this + // clear returns, or observes no current session and completes false itself. + val session = gattSessions.clear() + completePendingWrites(false) inFlightWrite = null stopScan() handler.removeCallbacksAndMessages(null) // heartbeat, rescan, connect/op watchdogs, write retries - opQueue.clear(); opBusy.set(false) - gatt?.let { runCatching { it.disconnect() }; runCatching { it.close() } } - gatt = null + opQueue.clear(); opBusy.set(false); bootstrapReadiness = null + session?.let { runCatching { it.disconnect() }; runCatching { it.close() } } } /** ANT-learned: a GATT link can stay "connected" while notifications silently stop (no disconnect @@ -102,13 +155,8 @@ class ZycleClient( override fun run() { if (stopped) return val g = gatt - if (g != null && lastMessageMs != 0L && System.currentTimeMillis() - lastMessageMs > HEARTBEAT_TIMEOUT_MS) { - FileLog.event("Zycle watchdog: silent ${System.currentTimeMillis() - lastMessageMs}ms -> reconnect") - gatt = null; lastMessageMs = 0L - onState(false) - opQueue.clear(); opBusy.set(false); syncOwed.set(false); burstEnqueued = false - runCatching { g.disconnect() }; runCatching { g.close() } - scheduleReconnect() + if (g != null && lastMessageMs != 0L && android.os.SystemClock.elapsedRealtime() - lastMessageMs > HEARTBEAT_TIMEOUT_MS) { + recycleGatt(g, "silent ${android.os.SystemClock.elapsedRealtime() - lastMessageMs}ms") } handler.postDelayed(this, HEARTBEAT_CHECK_MS) } @@ -121,30 +169,118 @@ class ZycleClient( handler.postDelayed({ reconnectPending.set(false); startScan() }, RECONNECT_DELAY_MS) } - /** Forward a write to the trainer's characteristic [charUuid] (control relay). Queued. */ - override fun write(charUuid: UUID, bytes: ByteArray, withResponse: Boolean): Boolean = - writeInternal(charUuid, bytes, withResponse, CONTROL_WRITE_RETRIES) + /** A timed-out Android GATT operation has no cancellation API. The only safe queue reset is therefore + * to retire the whole handle; callbacks already queued for it then fail the same identity gate. */ + private fun recycleGatt(g: BluetoothGatt, reason: String) { + gattSessions.retireIfCurrent(g) { FileLog.event("Zycle watchdog: $reason -> reconnect") } + } - private fun writeInternal(charUuid: UUID, bytes: ByteArray, withResponse: Boolean, retriesLeft: Int): Boolean { - val g = gatt ?: run { FileLog.event("Zycle write ${shortUuid(charUuid)} DROPPED — no trainer link"); return false } + /** Forward a write to the trainer's characteristic [charUuid] (control relay). Queued. */ + override fun write( + charUuid: UUID, + bytes: ByteArray, + withResponse: Boolean, + onComplete: (Boolean) -> Unit, + ): Boolean { + val ticket = TrainerWriteTicket(writeSeq.incrementAndGet(), onComplete) + if (stopped) { + FileLog.event("Zycle write ${shortUuid(charUuid)} DROPPED — client stopped") + ticket.complete(false) + return false + } + val g = gatt ?: run { + FileLog.event("Zycle write ${shortUuid(charUuid)} DROPPED — no trainer link") + ticket.complete(false) + return false + } // g.services is repopulated by discovery while this runs on the GATT-server binder thread val ch = runCatching { g.services.firstNotNullOfOrNull { s -> s.getCharacteristic(charUuid) } }.getOrNull() - ?: run { FileLog.event("Zycle write ${shortUuid(charUuid)} DROPPED — characteristic not found"); return false } + ?: run { + FileLog.event("Zycle write ${shortUuid(charUuid)} DROPPED — characteristic not found") + ticket.complete(false) + return false + } FileLog.event("Zycle write ${shortUuid(charUuid)} = ${FileLog.hex(bytes)}") - val seq = writeSeq.incrementAndGet() - enqueue { + return enqueueWrite(WriteReq(g, ch, charUuid, bytes, withResponse, CONTROL_WRITE_RETRIES, ticket)) + } + + private fun enqueueWrite(request: WriteReq): Boolean { + var queued = false + gattSessions.runIfCurrent(request.session) { + pendingWrites.add(request.ticket) + opQueue.add { executeWrite(request) } + queued = true + } + if (!queued) { + completeWrite(request, false) + return false + } + pump() + return true + } + + private fun executeWrite(request: WriteReq) { + if (stopped || gattSessions.current !== request.session) { + completeWrite(request, false) + opDone() + return + } + runCatching { @Suppress("DEPRECATION") run { - inFlightWrite = WriteReq(charUuid, bytes, withResponse, retriesLeft, seq) - ch.writeType = if (withResponse) BluetoothGattCharacteristic.WRITE_TYPE_DEFAULT + inFlightWrite = request + request.characteristic.writeType = if (request.withResponse) BluetoothGattCharacteristic.WRITE_TYPE_DEFAULT else BluetoothGattCharacteristic.WRITE_TYPE_NO_RESPONSE - ch.value = bytes - if (g.writeCharacteristic(ch) != true) { - FileLog.event("Zycle write ${shortUuid(charUuid)} REFUSED by stack"); inFlightWrite = null; opDone() + request.characteristic.value = request.bytes + if (request.session.writeCharacteristic(request.characteristic) != true) { + FileLog.event("Zycle write ${shortUuid(request.uuid)} REFUSED by stack" + + if (canRetry(request)) " — retry ${request.retriesLeft}" else "") + inFlightWrite = null + if (canRetry(request)) scheduleWriteRetry(request) else completeWrite(request, false) + opDone() } } + }.onFailure { + FileLog.event("Zycle write ${shortUuid(request.uuid)} FAILED before dispatch") + inFlightWrite = null + completeWrite(request, false) + opDone() + } + } + + private fun canRetry(request: WriteReq): Boolean = + request.retriesLeft > 0 && GattUuids.carriesControl(request.uuid) + + private fun scheduleWriteRetry(request: WriteReq) { + handler.postDelayed({ + if (!stopped && writeSeq.get() == request.ticket.sequence && gattSessions.current === request.session) { + FileLog.event("Zycle write ${shortUuid(request.uuid)} #${request.ticket.sequence} RETRY") + enqueueWrite(request.copy(retriesLeft = request.retriesLeft - 1)) + } else { + // The ordering invariant lives or dies here: without this line a superseded retry is + // indistinguishable from a lost write in the log. + FileLog.event("Zycle write ${shortUuid(request.uuid)} #${request.ticket.sequence} " + + "SUPERSEDED (now #${writeSeq.get()})") + completeWrite(request, false) + } + }, CONTROL_RETRY_DELAY_MS) + } + + private fun completeWrite(request: WriteReq, success: Boolean) { + pendingWrites.remove(request.ticket) + if (GattUuids.carriesControl(request.uuid)) + FileLog.event("Zycle write ${shortUuid(request.uuid)} #${request.ticket.sequence} " + + if (success) "COMPLETED" else "FAILED") + runCatching { request.ticket.complete(success) } + .onFailure { FileLog.event("Zycle write ${shortUuid(request.uuid)} completion callback FAILED") } + } + + private fun completePendingWrites(success: Boolean) { + pendingWrites.forEach { ticket -> + pendingWrites.remove(ticket) + runCatching { ticket.complete(success) } + .onFailure { FileLog.event("Zycle write completion callback FAILED") } } - return true } // ── scan ──────────────────────────────────────────────────────────────────────────────────────── @@ -196,12 +332,21 @@ class ZycleClient( val filters = if (pairedAddress.isNotEmpty()) listOf(android.bluetooth.le.ScanFilter.Builder().setDeviceAddress(pairedAddress).build()) else GattUuids.scanFilters(0x1826) - // BALANCED, not LOW_POWER: this scan runs while we have no trainer, and with the screen off - // LOW_POWER's duty cycle can take minutes to reacquire mid-ride. + // BALANCED, not LOW_POWER, for a REACQUISITION: with the screen off LOW_POWER's duty cycle can take + // minutes to find the trainer again mid-ride. That argument is about a scan following a connection we + // already had. A cold search is the other case and is not the same: the trainer simply isn't powered + // on, nothing stops a successful scan, and BALANCED's 25% radio duty then runs for hours. Cost of + // telling them apart: the first acquisition of the day takes a few seconds longer. val settings = android.bluetooth.le.ScanSettings.Builder() - .setScanMode(android.bluetooth.le.ScanSettings.SCAN_MODE_BALANCED).build() + .setScanMode(if (everConnected) android.bluetooth.le.ScanSettings.SCAN_MODE_BALANCED + else android.bluetooth.le.ScanSettings.SCAN_MODE_LOW_POWER).build() // A revoked BLUETOOTH_SCAN throws here; swallowing it while `scanning` was already true left the // client permanently dead and silent. Set the flag ONLY once the scan really started. + // Log the START, not just failures: without it a log cannot tell "scanning and the trainer is off" + // from "never started scanning", and it is the only way to time how long a cold acquisition takes + // (the cost E2's LOW_POWER duty cycle trades against) or to prove a reacquisition ran at BALANCED. + FileLog.event("Zycle scan start mode=${if (everConnected) "BALANCED" else "LOW_POWER"} " + + "filter=${if (pairedAddress.isNotEmpty()) "addr" else "FTMS"}") val started = runCatching { scanner.startScan(filters, settings, scanCallback) } if (started.isFailure) { FileLog.event("Zycle scan start threw: ${started.exceptionOrNull()}"); retryScanLater(); return @@ -232,19 +377,37 @@ class ZycleClient( if (stopped) { connecting.set(false); return } // stop() raced a scan result on a binder thread // TRANSPORT_LE explicitly: with TRANSPORT_AUTO a device that ever bonded as DUAL is attempted over // BR/EDR and fails with status=133 every time. + val attempt = Any() + connectAttempts.replace(attempt) + // Re-checked AFTER the token exists: stop() could have landed between the check above and this line, + // and it clears no token that had not been registered yet. From here on a stop is guaranteed to + // invalidate us. No monitor is held across connectGatt() — it can block for as long as the stack likes. + if (stopped) { connectAttempts.clearIfCurrent(attempt) { connecting.set(false) }; return } val g = runCatching { device.connectGatt(context, false, gattCallback, BluetoothDevice.TRANSPORT_LE) }.getOrNull() - gatt = g if (g == null) { // registerClient failed (client-interface exhaustion / stack restart) - FileLog.event("Zycle connectGatt returned null — rescheduling") - connecting.set(false); scheduleReconnect(); return + // Only if we still own the attempt: `connecting` and the retry belong to whoever replaced us. + if (connectAttempts.clearIfCurrent(attempt) { connecting.set(false) }) { + FileLog.event("Zycle connectGatt returned null — rescheduling") + scheduleReconnect() + } + return + } + // A handle nobody owns: stop(), or a newer attempt, landed while connectGatt blocked. Close it and + // touch NOTHING else — clearing `connecting` here would release the latch the live attempt holds, + // letting a scan result start a third connection behind its back. + if (!connectAttempts.clearIfCurrent(attempt) { gatt = g }) { + FileLog.event("Zycle connectGatt returned for a retired attempt — closing it") + runCatching { g.disconnect() }; runCatching { g.close() } + return } // Bound to THIS handle: a timeout left over from a previous attempt used to tear down the next one. val timeout = Runnable { - if (!stopped && connecting.get() && gatt === g) { + if (!stopped && connecting.get() && gattSessions.clearIfCurrent(g) { FileLog.event("Zycle connect timeout ${CONNECT_TIMEOUT_MS}ms -> retry") - gatt = null; connecting.set(false) + connecting.set(false) + }) { runCatching { g.disconnect() }; runCatching { g.close() } scheduleReconnect() } @@ -258,66 +421,96 @@ class ZycleClient( private val gattCallback = object : BluetoothGattCallback() { override fun onConnectionStateChange(g: BluetoothGatt, status: Int, newState: Int) { if (newState == BluetoothProfile.STATE_CONNECTED) { - if (gatt !== g) { runCatching { g.close() }; return } // orphaned handle — drop it - FileLog.event("Zycle connected status=$status") - connecting.set(false) - retryMs = SCAN_RETRY_MS // a good connection resets the backoff - lastMessageMs = System.currentTimeMillis() // start the silent-link window at connect - syncOwed.set(true); burstEnqueued = false - onState(true) - handler.post { runCatching { g.discoverServices() } } - // Floor under the mirror going on the air. Discovery can fail, be refused by the stack, or - // yield a profile with nothing to read; and a lost GATT callback costs OP_TIMEOUT_MS each. - // Waiting forever for a perfect sync is worse than advertising with a partial cache. - handler.postDelayed({ - if (syncOwed.get()) FileLog.event("Zycle sync fallback ${SYNC_FALLBACK_MS}ms -> advertising anyway") - fireSynced(g) - }, SYNC_FALLBACK_MS) + if (!gattSessions.runIfCurrent(g) { + FileLog.event("Zycle connected status=$status") + connecting.set(false) + retryMs = SCAN_RETRY_MS // a good connection resets the backoff + everConnected = true // ...and promotes every later scan to the reacquisition duty cycle + lastMessageMs = android.os.SystemClock.elapsedRealtime() // start the silent-link window at connect + syncOwed.set(true); burstEnqueued = false; bootstrapReadiness = null + onState(true) + handler.post { runCatching { g.discoverServices() } } + // A fallback may shorten a slow queue only after every required bootstrap result exists. + // Advertising a controllable profile without Feature/control or any power stream makes + // the client cache a broken trainer for the whole session. + handler.postDelayed({ + gattSessions.runIfCurrent(g) { + if (syncOwed.get() && bootstrapReadiness?.ready == true) { + FileLog.event("Zycle sync fallback ${SYNC_FALLBACK_MS}ms -> required bootstrap ready") + fireSynced(g) + } + } + }, SYNC_FALLBACK_MS) + }) runCatching { g.close() } // orphaned handle — drop it } else { FileLog.event("Zycle disconnected status=$status") runCatching { g.close() } - if (gatt !== g) return // a stale/superseded handle — don't touch the live connection's state - onState(false) - opQueue.clear(); opBusy.set(false); syncOwed.set(false); burstEnqueued = false - gatt = null; connecting.set(false); inFlightWrite = null; lastMessageMs = 0L - scheduleReconnect() + if (gattSessions.clearIfCurrent(g) { + onState(false) + completePendingWrites(false) + opQueue.clear(); opBusy.set(false); syncOwed.set(false); burstEnqueued = false + connecting.set(false); inFlightWrite = null; lastMessageMs = 0L + }) scheduleReconnect() } } override fun onServicesDiscovered(g: BluetoothGatt, status: Int) { - if (stopped || gatt !== g) return // stopped, or a callback from a handle we already replaced - if (status != BluetoothGatt.GATT_SUCCESS) { - Log.w(tag, "discover failed $status"); FileLog.event("Zycle discover FAILED status=$status"); return + if (stopped) return + gattSessions.runIfCurrent(g) { + if (status != BluetoothGatt.GATT_SUCCESS) { + Log.w(tag, "discover failed $status"); FileLog.event("Zycle discover FAILED status=$status") + recycleGatt(g, "service discovery failed status=$status") + return@runIfCurrent + } + lastMessageMs = android.os.SystemClock.elapsedRealtime() + val profile = buildProfile(g) + bootstrapReadiness = FtmsBootstrapReadiness( + controllable = profile.services.any { service -> + service.chars.any { it.uuid == GattUuids.FTMS_CONTROL_POINT } + }, + ) + FileLog.event("Zycle profile: " + profile.services.joinToString("; ") { s -> + "${s.uuid}[" + s.chars.joinToString(",") { "${shortUuid(it.uuid)}(p=${it.properties})" } + "]" + }) + onProfile(profile) + // Subscribe to every notify/indicate char, and read every readable char once — all serialised. + val svcs = g.services.filterNot { GattUuids.isStackService(it.uuid) } + // BEFORE the loops: an op the stack refuses completes synchronously inside pump(), so the + // whole burst can drain right here. The mirror must wait for the FULL queue to drain, not + // merely for the first subscription, or its read cache is still cold when it advertises. + burstEnqueued = true + // try/finally is load-bearing: an exception while building leaves no permanent queue latch. + burstBuilding = true + try { + // DATA STREAMS FIRST. Reads can take 0.5-2 s over the air; putting them first punches that + // gap in every reconnect. The cold-cache invariant still gates advertising on full drain. + for (svc in svcs) for (ch in svc.characteristics) + if ((ch.uuid == GattUuids.INDOOR_BIKE_DATA || ch.uuid == GattUuids.CYCLING_POWER_MEASUREMENT) && + ch.properties and (BluetoothGattCharacteristic.PROPERTY_NOTIFY or BluetoothGattCharacteristic.PROPERTY_INDICATE) != 0) + enqueueSubscribe(g, ch) + // READS NEXT: apps read FTMS Feature immediately and cache an empty answer for the session. + for (svc in svcs) for (ch in svc.characteristics) + if (ch.properties and BluetoothGattCharacteristic.PROPERTY_READ != 0) enqueueRead(g, ch) + for (svc in svcs) for (ch in svc.characteristics) + if (ch.uuid != GattUuids.INDOOR_BIKE_DATA && + ch.uuid != GattUuids.CYCLING_POWER_MEASUREMENT && + ch.properties and (BluetoothGattCharacteristic.PROPERTY_NOTIFY or BluetoothGattCharacteristic.PROPERTY_INDICATE) != 0) + enqueueSubscribe(g, ch) + } finally { burstBuilding = false } + // Also drains a profile with nothing readable/notifiable instead of hanging the sync latch. + pump() } - lastMessageMs = System.currentTimeMillis() // discovery counts as life, or the watchdog recycles us mid-subscribe - val profile = buildProfile(g) - FileLog.event("Zycle profile: " + profile.services.joinToString("; ") { s -> - "${s.uuid}[" + s.chars.joinToString(",") { "${shortUuid(it.uuid)}(p=${it.properties})" } + "]" - }) - onProfile(profile) - // Subscribe to every notify/indicate char, and read every readable char once — all serialised. - val svcs = g.services.filterNot { GattUuids.isStackService(it.uuid) } - // BEFORE the loops: an op the stack refuses completes synchronously inside pump(), so the whole - // burst can drain right here — and a flag set afterwards would arm an already-empty queue, - // leaving the mirror permanently off the air. - burstEnqueued = true - // READS FIRST: an app connecting to the mirror reads FTMS Feature almost immediately, and a cold - // cache there reads to it as "this machine has no capabilities" for the whole session. - for (svc in svcs) for (ch in svc.characteristics) - if (ch.properties and BluetoothGattCharacteristic.PROPERTY_READ != 0) enqueueRead(g, ch) - for (svc in svcs) for (ch in svc.characteristics) - if (ch.properties and (BluetoothGattCharacteristic.PROPERTY_NOTIFY or BluetoothGattCharacteristic.PROPERTY_INDICATE) != 0) - enqueueSubscribe(g, ch) - pump() // a profile with nothing readable/notifiable enqueues nothing: drain now, don't hang } override fun onDescriptorWrite(g: BluetoothGatt, descriptor: BluetoothGattDescriptor, status: Int) { - val u = descriptor.characteristic.uuid - // a failed CCCD write means that characteristic silently never notifies — never let it pass quietly - if (status != BluetoothGatt.GATT_SUCCESS) - FileLog.event("Zycle subscribe ${shortUuid(u)} FAILED status=$status") - lastMessageMs = System.currentTimeMillis() - opDone() + gattSessions.runIfCurrent(g) { + val u = descriptor.characteristic.uuid + if (descriptor.uuid == cccd) markBootstrapSubscription(u, status == BluetoothGatt.GATT_SUCCESS) + if (status != BluetoothGatt.GATT_SUCCESS) + FileLog.event("Zycle subscribe ${shortUuid(u)} FAILED status=$status") + lastMessageMs = android.os.SystemClock.elapsedRealtime() + opDone() + } } override fun onMtuChanged(g: BluetoothGatt, mtu: Int, status: Int) { @@ -326,38 +519,63 @@ class ZycleClient( @Deprecated("Deprecated in Java") override fun onCharacteristicRead(g: BluetoothGatt, ch: BluetoothGattCharacteristic, status: Int) { - if (status == BluetoothGatt.GATT_SUCCESS) { - val v = @Suppress("DEPRECATION") (ch.value?.copyOf() ?: ByteArray(0)) - FileLog.event("Zycle read ${shortUuid(ch.uuid)} = ${FileLog.hex(v)}") // identity/feature/ranges values - onValue(ch.uuid, v) - } else FileLog.event("Zycle read ${shortUuid(ch.uuid)} failed status=$status") - lastMessageMs = System.currentTimeMillis() - opDone() + gattSessions.runIfCurrent(g) { + if (status == BluetoothGatt.GATT_SUCCESS) { + val v = @Suppress("DEPRECATION") (ch.value?.copyOf() ?: ByteArray(0)) + // A GATT_SUCCESS read of a too-short value is not a Feature. Validate BEFORE + // publishing: onValue() seeds lastValues and any already-connected mirror client, + // which would then cache "no ERG, no automatic mode" for its whole connection. + // 0x2ACC is two mandatory 32-bit fields: Fitness Machine Features AND Target Setting + // Features. A 4-byte read has no Target Setting Features, so the client concludes + // "no ERG, no automatic mode" — the exact failure this gate exists to prevent. + val usable = ch.uuid != FTMS_FEATURE || v.size >= 8 + FileLog.event("Zycle read ${shortUuid(ch.uuid)} = ${FileLog.hex(v)}" + + if (!usable) " — REJECTED, too short for FTMS Feature" else "") + if (usable) onValue(ch.uuid, v) + if (ch.uuid == FTMS_FEATURE) bootstrapReadiness?.featureRead = usable + } else { + FileLog.event("Zycle read ${shortUuid(ch.uuid)} failed status=$status") + if (ch.uuid == FTMS_FEATURE) bootstrapReadiness?.featureRead = false + } + lastMessageMs = android.os.SystemClock.elapsedRealtime() + opDone() + } } override fun onCharacteristicWrite(g: BluetoothGatt, ch: BluetoothGattCharacteristic, status: Int) { - lastMessageMs = System.currentTimeMillis() - // only the write this callback is FOR: a late status used to be attributed to whatever write - // happened to be in the slot, re-sending someone else's ERG target - val w = inFlightWrite?.takeIf { it.uuid == ch.uuid } - if (w != null) inFlightWrite = null - if (status != BluetoothGatt.GATT_SUCCESS) { - // Retry a failed CONTROL write (the trainer occasionally NAKs with status 133), but only if a - // newer control write hasn't superseded it (w.seq == writeSeq) — never re-send a stale target. - val retry = w != null && w.retriesLeft > 0 && GattUuids.carriesControl(w.uuid) && w.seq == writeSeq.get() && !stopped - FileLog.event("Zycle write ${shortUuid(ch.uuid)} status=$status" + if (retry) " — retry ${w!!.retriesLeft}" else "") - if (retry) handler.postDelayed({ writeInternal(w!!.uuid, w.bytes, w.withResponse, w.retriesLeft - 1) }, CONTROL_RETRY_DELAY_MS) + gattSessions.runIfCurrent(g) { + lastMessageMs = android.os.SystemClock.elapsedRealtime() + // Attribute a status only to the write this callback names. A late callback must not retry + // whichever newer ERG target happens to occupy the slot. + val w = inFlightWrite?.takeIf { it.session === g && it.uuid == ch.uuid } + if (w != null) inFlightWrite = null + if (w != null && status == BluetoothGatt.GATT_SUCCESS) { + completeWrite(w, true) + } else if (status != BluetoothGatt.GATT_SUCCESS) { + // Decide supersession when the delayed retry runs. A newer command must not relabel a + // write the Android stack already accepted while this callback was outstanding. + val retry = w != null && canRetry(w) + FileLog.event("Zycle write ${shortUuid(ch.uuid)} status=$status" + if (retry) " — retry ${w!!.retriesLeft}" else "") + if (retry) scheduleWriteRetry(w!!) else if (w != null) completeWrite(w, false) + } + opDone() } - opDone() } @Deprecated("Deprecated in Java") override fun onCharacteristicChanged(g: BluetoothGatt, ch: BluetoothGattCharacteristic) { if (stopped) return // in-flight notification after stop() — not our data any more - val value = @Suppress("DEPRECATION") (ch.value?.copyOf() ?: ByteArray(0)) - lastMessageMs = System.currentTimeMillis() // feed the silent-link watchdog - logNotif(ch.uuid, value) // every notification, unthrottled - onValue(ch.uuid, value) + // The whole relay stays INSIDE the session gate. receiveOwner identifies the source OBJECT, not + // the GATT handle, so a frame from a handle this client already retired still passes it — and in + // MirrorServer it would consume the reanchorLevel the disconnect just armed for the replacement, + // reporting an outage's level movement as a rider button press. Cheap to hold: the notify + // fan-out is posted to main by MirrorServer (see onZycleValue), never called under this monitor. + gattSessions.runIfCurrent(g) { + val value = @Suppress("DEPRECATION") (ch.value?.copyOf() ?: ByteArray(0)) + lastMessageMs = android.os.SystemClock.elapsedRealtime() + logNotif(ch.uuid, value) + onValue(ch.uuid, value) + } } } @@ -381,9 +599,31 @@ class ZycleClient( ) private fun enqueueSubscribe(g: BluetoothGatt, ch: BluetoothGattCharacteristic, retry: Boolean = true): Unit = enqueue { - g.setCharacteristicNotification(ch, true) + // The CCCD write tells the TRAINER to send; this tells ANDROID to deliver. If only the former + // succeeds we advertise as controllable and no Control Point response ever reaches us. + if (!g.setCharacteristicNotification(ch, true)) { + // Requeue once, like the writeDescriptor refusal below: a transient false during re-discovery + // would otherwise fail readiness permanently and drop us into a reconnect loop. + FileLog.event("Zycle subscribe ${shortUuid(ch.uuid)} — local registration REFUSED" + + if (retry) " — requeueing" else " — giving up") + if (retry) handler.postDelayed({ + gattSessions.runIfCurrent(g) { + enqueueSubscribe(g, ch, retry = false) + opDone() + } + }, OP_REQUEUE_MS) else { + markBootstrapSubscription(ch.uuid, false) + opDone() + } + return@enqueue + } val d = ch.getDescriptor(cccd) - if (d == null) { FileLog.event("Zycle subscribe ${shortUuid(ch.uuid)} — no CCCD"); opDone(); return@enqueue } + if (d == null) { + markBootstrapSubscription(ch.uuid, false) + FileLog.event("Zycle subscribe ${shortUuid(ch.uuid)} — no CCCD") + opDone() + return@enqueue + } FileLog.event("Zycle subscribe ${shortUuid(ch.uuid)}") @Suppress("DEPRECATION") run { @@ -391,8 +631,15 @@ class ZycleClient( BluetoothGattDescriptor.ENABLE_INDICATION_VALUE else BluetoothGattDescriptor.ENABLE_NOTIFICATION_VALUE if (g.writeDescriptor(d) != true) { FileLog.event("Zycle subscribe ${shortUuid(ch.uuid)} REFUSED by stack" + if (retry) " — requeueing" else " — giving up") - if (retry) handler.postDelayed({ if (!stopped && gatt === g) enqueueSubscribe(g, ch, retry = false) }, OP_REQUEUE_MS) - opDone() + if (retry) handler.postDelayed({ + gattSessions.runIfCurrent(g) { + enqueueSubscribe(g, ch, retry = false) + opDone() + } + }, OP_REQUEUE_MS) else { + markBootstrapSubscription(ch.uuid, false) + opDone() + } } } } @@ -400,37 +647,65 @@ class ZycleClient( private fun enqueueRead(g: BluetoothGatt, ch: BluetoothGattCharacteristic, retry: Boolean = true): Unit = enqueue { if (g.readCharacteristic(ch) != true) { FileLog.event("Zycle read ${shortUuid(ch.uuid)} REFUSED by stack" + if (retry) " — requeueing" else " — giving up") - if (retry) handler.postDelayed({ if (!stopped && gatt === g) enqueueRead(g, ch, retry = false) }, OP_REQUEUE_MS) - opDone() + if (retry) handler.postDelayed({ + gattSessions.runIfCurrent(g) { + enqueueRead(g, ch, retry = false) + opDone() + } + }, OP_REQUEUE_MS) else { + if (ch.uuid == FTMS_FEATURE) bootstrapReadiness?.featureRead = false + opDone() + } + } + } + + private fun markBootstrapSubscription(uuid: UUID, success: Boolean) { + when (uuid) { + GattUuids.FTMS_CONTROL_POINT -> bootstrapReadiness?.controlPointSubscribed = success + GattUuids.INDOOR_BIKE_DATA -> bootstrapReadiness?.indoorBikeSubscribed = success + GattUuids.CYCLING_POWER_MEASUREMENT -> bootstrapReadiness?.cyclingPowerSubscribed = success } } // ── GATT op serialisation ──────────────────────────────────────────────────────────────────────── private fun enqueue(op: () -> Unit) { opQueue.add(op); pump() } + /** Set while the opening burst is still being ENQUEUED. `enqueue` pumps on every add, so without this the + * first op runs immediately — and an op the stack refuses completes synchronously, draining a queue whose + * remaining ops have not been added yet. `pump()` then sees it empty and fires onSynced, putting the + * mirror on the air with a cold read cache: the very thing `burstEnqueued` exists to prevent. */ + @Volatile private var burstBuilding = false @Volatile private var opWatchdog: Runnable? = null private fun pump() { + if (burstBuilding) return // nothing may run until the whole burst is queued — see burstBuilding if (opBusy.compareAndSet(false, true)) { val op = opQueue.poll() if (op == null) { opBusy.set(false) // Drained: the opening burst is done, so the mirror now has every readable value we can give it. - if (burstEnqueued) gatt?.let { fireSynced(it) } + if (burstEnqueued && syncOwed.get()) gatt?.let { session -> + val readiness = bootstrapReadiness + if (readiness?.ready == true) fireSynced(session) + else { + val missing = readiness?.missingRequirements?.joinToString() ?: "service discovery" + FileLog.event("Zycle bootstrap incomplete: $missing -> reconnect") + recycleGatt(session, "bootstrap missing $missing") + } + } return } + val session = gatt + if (session == null) { opQueue.clear(); opBusy.set(false); return } // Per-op watchdog: a LOST GATT callback (flaky link) would otherwise latch opBusy forever and every // later control/ERG write would sit undispatched while power keeps streaming (invisible failure). - // opDone() cancels this on normal completion; the token guard covers the concurrent-fire edge. - // ponytail: a real callback arriving >OP_TIMEOUT_MS LATE (not lost — link already badly degraded) - // can still double-advance for an instant. Self-healing and strictly better than the old permanent - // wedge; fully closing it needs matching each callback to its op (fragile) — not worth it. + // opDone() cancels this on normal completion; token + session identity cover the concurrent edge. val token = opToken.incrementAndGet() val w = Runnable { - if (opBusy.get() && opToken.get() == token) { - FileLog.event("Zycle GATT op timeout ${OP_TIMEOUT_MS}ms -> unstick queue") - inFlightWrite = null - opDone() - } + gattSessions.timeoutIfCurrent( + session, + stillPending = { opBusy.get() && opToken.get() == token }, + onRetiring = { FileLog.event("Zycle watchdog: GATT op timeout ${OP_TIMEOUT_MS}ms -> reconnect") }, + ) } opWatchdog = w handler.postDelayed(w, OP_TIMEOUT_MS) @@ -450,6 +725,7 @@ class ZycleClient( const val CONTROL_WRITE_RETRIES = 2 // resend a control write that NAKs (status 133) up to twice const val CONTROL_RETRY_DELAY_MS = 250L const val OP_TIMEOUT_MS = 4000L // unstick the GATT queue if a callback is ever lost (flaky link) - const val SYNC_FALLBACK_MS = 6000L // go on the air with a partial cache rather than never + const val SYNC_FALLBACK_MS = 6000L // only shorten a slow queue after required bootstrap is ready + val FTMS_FEATURE: UUID = GattUuids.uuid16(0x2ACC) } } diff --git a/app/src/main/java/com/enderthor/trainerbridgeble/correction/ErgBias.kt b/app/src/main/java/com/enderthor/trainerbridgeble/correction/ErgBias.kt new file mode 100644 index 0000000..f554313 --- /dev/null +++ b/app/src/main/java/com/enderthor/trainerbridgeble/correction/ErgBias.kt @@ -0,0 +1,94 @@ +package com.enderthor.trainerbridgeble.correction + +import kotlin.math.roundToInt + +/** + * Learns how far the trainer settles ABOVE the raw target we command it. + * + * Measured over three sessions against a power meter: the Zycle holds ~8 W (raw) more than commanded. The + * app runs its own ERG loop on the power we report, sees itself over target, and walks its setpoint down a + * click at a time — which is what "the intensity goes down by itself, as if the minus button pressed + * itself" actually is. The app is not misbehaving and neither are we: it is correcting a real overshoot. + * + * We cannot make the trainer track better, so we command it LOWER by exactly what it overshoots and it + * lands where the app asked. Learned rather than configured: it is a property of this particular trainer + * (and its temperature, and its belt), so no one can be expected to type the number in. + * + * It cannot wind up. Commanding `target - bias` makes the trainer deliver `(target - bias) + overshoot`, + * so the sampled error stays at `overshoot` whatever the bias is — the EMA converges on the trainer's + * error, it does not chase its own output the way an error integrator would. + * + * Pure logic, no Android: the caller passes the clock (as [com.enderthor.trainerbridgeble.CorrectedFeed] + * does) so this is unit-testable. + */ +object ErgBias { + + /** Settling time before a sample counts: the trainer ramps to a new target over several seconds, and + * that ramp is not the steady-state error we are after. */ + private const val SETTLE_MS = 12_000L + /** Below this raw target the ERG floor may be holding the command above what the app asked, so + * "measured - commanded" no longer measures the trainer. (floorRaw is ~25 with the usual settings.) */ + private const val MIN_TARGET_W = 40 + /** ~100 samples to converge; at the trainer's 0.5 Hz that is roughly three minutes. Slow on purpose: + * the rider surging over target must not move it. */ + private const val ALPHA = 0.02 + private const val MAX_BIAS_W = 30 + /** One absurd sample (a dropout, a standing sprint) must not drag the average. */ + private const val MAX_SAMPLE_W = 60 + + private const val OP_SET_TARGET_POWER = 0x05 + + @Volatile private var bias = 0.0 + private var commandedRaw: Int? = null + private var commandedAtMs = 0L + + /** The learned bias, in raw watts, to subtract from the ERG command. */ + val watts: Int get() = bias.roundToInt() + + /** The raw ERG target currently being measured against, or null if none is active. Diagnostics only — + * it is how a log answers "did the resistance button actually retire the command?". */ + val commanded: Int? get() = commandedRaw + + /** Restore what a previous session learned, so a ride starts calibrated instead of re-converging. Also + * retires any active command: this is a session boundary, and a command left over from the last one + * would read as long settled and be measured against power from a different ride. */ + @Synchronized fun seed(w: Int) { + bias = w.coerceIn(-MAX_BIAS_W, MAX_BIAS_W).toDouble() + forget() + } + + /** + * A control write on its way to the trainer — already inverse-corrected, i.e. exactly the raw watts the + * trainer is being told to hold. Anything that ends ERG (reset, stop, resistance or simulation mode) + * retires the active command; the rest (request control, start/resume) leave it alone. + */ + @Synchronized fun onControl(bytes: ByteArray, nowMs: Long) { + if (bytes.isEmpty()) return + when (bytes[0].toInt() and 0xFF) { + OP_SET_TARGET_POWER -> if (bytes.size >= 3) { + val raw = ((bytes[1].toInt() and 0xFF) or ((bytes[2].toInt() and 0xFF) shl 8)).toShort().toInt() + if (raw != commandedRaw) { commandedRaw = raw; commandedAtMs = nowMs } + } + 0x01, 0x04, 0x08, 0x11 -> forget() + } + } + + /** + * A raw power reading from the trainer. Returns the new bias when its whole-watt value changed (so the + * caller can persist it), null otherwise. + */ + @Synchronized fun onPower(rawWatts: Int, nowMs: Long): Int? { + val target = commandedRaw ?: return null + if (target < MIN_TARGET_W) return null + if (rawWatts <= 0) return null // not pedalling: says nothing about tracking + if (nowMs - commandedAtMs < SETTLE_MS) return null // still ramping + val before = watts + val sample = (rawWatts - target).coerceIn(-MAX_SAMPLE_W, MAX_SAMPLE_W) + bias = (bias + ALPHA * (sample - bias)).coerceIn(-MAX_BIAS_W.toDouble(), MAX_BIAS_W.toDouble()) + return watts.takeIf { it != before } + } + + /** The trainer dropped, or ERG ended: there is no active command to measure against any more. The + * learned bias survives — it belongs to the trainer, not to the session. */ + @Synchronized fun forget() { commandedRaw = null; commandedAtMs = 0L } +} diff --git a/app/src/main/res/values-es/strings.xml b/app/src/main/res/values-es/strings.xml index 926a11c..dee589c 100644 --- a/app/src/main/res/values-es/strings.xml +++ b/app/src/main/res/values-es/strings.xml @@ -42,6 +42,8 @@ Identidad anunciada Nombre con el que nos ven las apps. DÉJALO VACÍO para usar el nombre Bluetooth del propio dispositivo: es lo más simple y así no se cambia el nombre del aparato. Es cosmético en cualquier caso: no afecta a lo que la app puede hacer con el rodillo. Opciones + Evitar que el Karoo se apague (enciende la pantalla cada 5 min - gasta bateria; se apaga a los 10 min sin ride) + Mantener encendida ESTA pantalla mientras esté abierta (el Karoo se apaga solo sin ride) Guardar log (CSV) Modo simulación (sin bici) Salida ANT+ (potencia corregida a reloj/ciclocomputador) @@ -56,6 +58,8 @@ buscando trainer… iniciando… app conectada (%d) + una app controla el rodillo + no se pudo mantener la CPU activa app desconectada (%d) anunciando %s fallo al anunciar (%d) diff --git a/app/src/main/res/values/strings.xml b/app/src/main/res/values/strings.xml index 51f7695..7ad4ed9 100644 --- a/app/src/main/res/values/strings.xml +++ b/app/src/main/res/values/strings.xml @@ -42,6 +42,8 @@ Advertised identity Name the apps see us as. LEAVE IT EMPTY to use this device\'s own Bluetooth name: simplest, and your device name is never changed. Cosmetic either way — it does not affect what an app can do with the trainer. Options + Keep the Karoo awake (wakes the screen every 5 min - uses battery; it powers off 10 min after the screen sleeps with no ride) + Keep THIS screen on while it is open (the Karoo powers off by itself with no ride) Save log (CSV) Simulation mode (no bike) ANT+ output (corrected power to watch/bike computer) @@ -56,6 +58,8 @@ searching trainer… starting… app connected (%d) + an app is controlling the trainer + could not keep the CPU awake app disconnected (%d) advertising %s advertise failed (%d) diff --git a/app/src/test/java/com/enderthor/trainerbridgeble/RuntimeHardeningTest.kt b/app/src/test/java/com/enderthor/trainerbridgeble/RuntimeHardeningTest.kt new file mode 100644 index 0000000..cd3fdbc --- /dev/null +++ b/app/src/test/java/com/enderthor/trainerbridgeble/RuntimeHardeningTest.kt @@ -0,0 +1,546 @@ +package com.enderthor.trainerbridgeble + +import java.util.concurrent.CountDownLatch +import java.util.concurrent.TimeUnit +import kotlin.concurrent.thread +import org.junit.Assert.assertArrayEquals +import org.junit.Assert.assertEquals +import org.junit.Assert.assertFalse +import org.junit.Assert.assertNotNull +import org.junit.Assert.assertNull +import org.junit.Assert.assertTrue +import org.junit.Test + +/** + * COORDINATOR CONTRACT ONLY. These are pure-JVM tests of the ownership primitives, with production's own + * call shapes. They deliberately do NOT prove any Android BLE behaviour, and cannot: a really-blocked + * connectGatt(), a GATT-server callback after close(), writeCharacteristic() blocking Binder while main + * runs stopEmit(), an accepted advertising start whose stop is dropped and whose callback is lost, the + * number of registrations actually live in the controller, adapter OFF/ON or a Bluetooth process death, + * and the real Handler/main/Binder ordering on the device all remain device-validation territory. + * Adding Robolectric would not move that line — it reproduces none of the above — so it is not used. + * + * Three purely LOGICAL gaps remain too, and are not covered here either: + * 1. `ZycleClient.connect()`'s `stopped` re-check after registering its token — a field read inside a + * production method, not a coordinator contract. + * 2. `MirrorServer`'s advOrphans / lastAdvCallback cross-instance handoff, including the resolved-vs- + * unresolved distinction. It lives entirely in an Android-typed class; a permanently-stranded orphan + * got through this suite once already, so treat that path as device-validated only. + * 3. That the production toZycle lambda really dispatches write() OUTSIDE the emit monitor. Only the + * ownership rejection is checked below; the call shape is not. + */ +class RuntimeHardeningTest { + private fun admitted(c: FtmsControlCoordinator.Admission?) = + (c as FtmsControlCoordinator.Admission.Admitted).procedure + + private fun rejected(result: Int, client: FtmsControlCoordinator.Client?) = + FtmsControlCoordinator.Admission.Rejected(result, client) + + private val erg = byteArrayOf(0x05, 0xF0.toByte(), 0x00) // Set Target Power 240 W + private val res = byteArrayOf(0x04, 0x24, 0x00) // Set Target Resistance 36 + + @Test fun localProcedureBlocksExternalAndDrainsWithoutClientNotification() { + val coordinator = FtmsControlCoordinator() + val a = coordinator.connected("A") + + assertNotNull(coordinator.admitLocal(0x04, res)) + assertEquals(rejected(FtmsControlCoordinator.OPERATION_FAILED, a), coordinator.admit("A", 0x00, null)) + assertNull(coordinator.response(0x05, FtmsControlCoordinator.SUCCESS)) + assertEquals(rejected(FtmsControlCoordinator.OPERATION_FAILED, a), coordinator.admit("A", 0x00, null)) + assertNull(coordinator.response(0x04, FtmsControlCoordinator.SUCCESS)?.client) + assertNotNull(admitted(coordinator.admit("A", 0x00, null))) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + assertNull(coordinator.admitLocal(0x04, res)) + } + + /** The C1 fix, and the bug the first attempt at it introduced: a LOCAL procedure has no client, so a + * `Client?` return could not distinguish "timed out" from "not the pending one". Skipping recovery on + * that null left the session quarantined with nothing able to lift it for the rest of the ride. */ + @Test fun aTimedOutLocalProcedureStillReportsItsTerminationSoRecoveryRuns() { + val coordinator = FtmsControlCoordinator() + val local = coordinator.admitLocal(0x04, res)!! + assertNull(local.client) + + val terminated = coordinator.timedOut(local) + assertNotNull(terminated) // matched, even with no client to notify + assertNull(terminated!!.client) + assertEquals(local, terminated.procedure) + } + + @Test fun anUnansweredProcedureIsReleasedByItsDeadlineAndQuarantinesTheLink() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) // A owns control + val stuck = admitted(coordinator.admit("A", 0x04, res)) // trainer never answers + + assertEquals(FtmsControlCoordinator.OPERATION_FAILED, + (coordinator.admit("A", 0x04, res) as FtmsControlCoordinator.Admission.Rejected).result) + assertEquals("A", coordinator.timedOut(stuck)?.client?.address) + // quarantined until the trainer link is recycled — not silently reopened + assertEquals(FtmsControlCoordinator.OPERATION_FAILED, + (coordinator.admit("A", 0x04, res) as FtmsControlCoordinator.Admission.Rejected).result) + coordinator.trainerReady() + assertNotNull(admitted(coordinator.admit("A", 0x04, res))) + } + + @Test fun anExpiredDeadlineCannotTerminateTheProcedureThatReplacedIt() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + val first = admitted(coordinator.admit("A", 0x04, res)) + coordinator.response(0x04, FtmsControlCoordinator.SUCCESS) + val second = admitted(coordinator.admit("A", 0x04, res)) + + assertNull(coordinator.timedOut(first)) // stale: must not quarantine or cancel + assertNull(coordinator.transportFailed(first)) // ...and must not disarm the newer deadline + assertEquals("A", coordinator.transportFailed(second)?.client?.address) + } + + /** The payload must ride WITH the procedure. As a side slot, one procedure's response committed + * another's target — teaching ERG bias a number the machine was never holding. */ + @Test fun aResponseCommitsTheBytesOfTheProcedureItTerminated() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + + val ergProcedure = admitted(coordinator.admit("A", 0x05, erg)) + assertArrayEquals(erg, coordinator.transportFailed(ergProcedure)?.bytes) // failed: bytes came back + // ...and the slot is empty afterwards, so a later local success cannot commit them + val local = coordinator.admitLocal(0x04, res) + assertNull(local) // A still owns control + coordinator.trainerDropped() + val afterDrop = coordinator.admitLocal(0x04, res)!! + assertArrayEquals(res, coordinator.response(0x04, FtmsControlCoordinator.SUCCESS)?.bytes) + assertEquals(0x04, afterDrop.opcode) + } + + /** The local button carries 0x04, which is ErgBias's signal to retire an armed ERG target. Routing it + * through the mirror without a payload silently stopped that signal from ever arriving. */ + @Test fun aLocalProcedureCarriesItsOwnBytesToTheCommitPoint() { + val coordinator = FtmsControlCoordinator() + coordinator.admitLocal(0x04, res) + val terminated = coordinator.response(0x04, FtmsControlCoordinator.SUCCESS) + assertNotNull(terminated) + assertArrayEquals(res, terminated!!.bytes) + assertNull(terminated.client) + } + + /** The C2 fix. The identity lookup and the admission are one step, so a disconnect cannot land between + * them and let a client that is already gone be promoted to owner — locking out its own reconnect. */ + @Test fun admissionAfterDisconnectIsRefusedRatherThanPromotingAGhost() { + val coordinator = FtmsControlCoordinator() + val first = coordinator.connected("A") + coordinator.disconnected("A") + + assertNull(coordinator.admit("A", 0x00, null)) // fail closed: no live identity for that address + val second = coordinator.connected("A") + assertTrue(first != second) // reconnect gets its own generation + assertEquals(second, admitted(coordinator.admit("A", 0x00, null)).client) + assertEquals(second, coordinator.response(0x00, FtmsControlCoordinator.SUCCESS)?.client) + } + + @Test fun disconnectReportsWhenPendingProcedureWasLost() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A") + val b = coordinator.connected("B") + val lost = admitted(coordinator.admit("A", 0x00, null)) + + assertEquals(lost, coordinator.disconnected("A")?.procedure) + assertEquals(rejected(FtmsControlCoordinator.OPERATION_FAILED, b), coordinator.admit("B", 0x00, null)) + coordinator.trainerReady() + assertNotNull(admitted(coordinator.admit("B", 0x00, null))) + } + + @Test fun disconnectWithoutAPendingProcedureRemovesTheIdentityAndReportsNoLoss() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A") + assertNull(coordinator.disconnected("A")) + assertNull(coordinator.identity("A")) // the key really is gone, not merely unreported + assertNull(coordinator.disconnected("A")) // idempotent: no second recycle + } + + @Test fun firstSuccessfulRequestControlOwnsFtms() { + val coordinator = FtmsControlCoordinator() + val a = coordinator.connected("A") + assertEquals(a, admitted(coordinator.admit("A", 0x00, null)).client) + assertEquals(a, coordinator.response(0x00, FtmsControlCoordinator.SUCCESS)?.client) + assertNotNull(admitted(coordinator.admit("A", 0x05, erg))) + } + + @Test fun secondClientCannotControlOrStealOwnership() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A"); val b = coordinator.connected("B") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + + assertEquals(rejected(FtmsControlCoordinator.CONTROL_NOT_PERMITTED, b), coordinator.admit("B", 0x05, erg)) + assertEquals(rejected(FtmsControlCoordinator.CONTROL_NOT_PERMITTED, b), coordinator.admit("B", 0x00, null)) + } + + /** A terminal indication that never reached its origin leaves that controller waiting forever; + * dropping the claim is what lets anyone else — including its own reconnect — arbitrate again. */ + @Test fun releasingAnUndeliverableOwnerReopensArbitration() { + val coordinator = FtmsControlCoordinator() + val a = coordinator.connected("A") + val b = coordinator.connected("B") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + + assertEquals(rejected(FtmsControlCoordinator.CONTROL_NOT_PERMITTED, b), coordinator.admit("B", 0x00, null)) + assertTrue(coordinator.releaseOwner(a)) + assertFalse(coordinator.releaseOwner(a)) // only the current owner, only once + assertNotNull(admitted(coordinator.admit("B", 0x00, null))) + } + + @Test fun onlyOneProcedureCanBePending() { + val coordinator = FtmsControlCoordinator() + val a = coordinator.connected("A") + val first = admitted(coordinator.admit("A", 0x00, null)) + assertEquals(rejected(FtmsControlCoordinator.OPERATION_FAILED, a), coordinator.admit("A", 0x00, null)) + coordinator.transportFailed(first) + assertNotNull(admitted(coordinator.admit("A", 0x00, null))) + } + + @Test fun responseRoutesOnlyToMatchingOrigin() { + val coordinator = FtmsControlCoordinator() + val a = coordinator.connected("A") + coordinator.admit("A", 0x00, null) + assertNull(coordinator.response(0x05, FtmsControlCoordinator.SUCCESS)) + assertEquals(a, coordinator.response(0x00, FtmsControlCoordinator.SUCCESS)?.client) + assertNotNull(admitted(coordinator.admit("A", 0x05, erg))) + } + + @Test fun failedRequestControlDoesNotAcquireOwnership() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A"); val b = coordinator.connected("B") + coordinator.admit("A", 0x00, null) + assertEquals("A", coordinator.response(0x00, FtmsControlCoordinator.OPERATION_FAILED)?.client?.address) + assertEquals(b, admitted(coordinator.admit("B", 0x00, null)).client) + } + + @Test fun ownerDisconnectAndTrainerDropClearOwnership() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + + coordinator.admit("A", 0x05, erg) + coordinator.disconnected("A") + coordinator.trainerDropped() + coordinator.trainerReady() + val b = coordinator.connected("B") + coordinator.admit("B", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + coordinator.admit("B", 0x05, erg) + assertEquals(b, coordinator.trainerDropped()) + coordinator.connected("A") + assertNotNull(admitted(coordinator.admit("A", 0x00, null))) + } + + /** A local GATT server rebuild closes the server, and Android raises no disconnect callbacks for the + * connections it kills. Keeping ownership across that stranded ERG on a dead generation. */ + @Test fun teardownDropsOwnershipAndEveryConnectionIdentity() { + val coordinator = FtmsControlCoordinator() + val a = coordinator.connected("A") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + + coordinator.clear() + assertNull(coordinator.identity("A")) + assertNull(coordinator.admit("A", 0x00, null)) // the old handle is gone, not merely stale + val reconnected = coordinator.connected("A") + assertTrue(a != reconnected) + assertEquals(reconnected, admitted(coordinator.admit("A", 0x00, null)).client) + assertEquals(reconnected, coordinator.response(0x00, FtmsControlCoordinator.SUCCESS)?.client) + } + + /** The guard that stops a late arm from stripping a healthy procedure of its only deadline. The local + * button path crosses two main-loop hops, so its arm routinely lands after a newer procedure's. */ + @Test fun onlyTheLiveProcedureIsStillPending() { + val coordinator = FtmsControlCoordinator() + coordinator.connected("A") + val local = coordinator.admitLocal(0x04, res)!! + assertTrue(coordinator.isPending(local)) + + coordinator.response(0x04, FtmsControlCoordinator.SUCCESS) + assertFalse(coordinator.isPending(local)) // ended: a stale arm must bail here + + val next = admitted(coordinator.admit("A", 0x00, null)) + assertTrue(coordinator.isPending(next)) + assertFalse(coordinator.isPending(local)) // ...and must not adopt the newer one either + } + + /** A rejection issued while the client did NOT own control must carry no authority to release + * ownership that same client legitimately acquires afterwards. */ + @Test fun ownershipAuthorityIsScopedToTheClientThatActuallyOwns() { + val coordinator = FtmsControlCoordinator() + val a = coordinator.connected("A") + val b = coordinator.connected("B") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + + assertTrue(coordinator.owns(a)) + assertFalse(coordinator.owns(b)) // B's rejection may not release anything + coordinator.disconnected("A") + coordinator.admit("B", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + assertTrue(coordinator.owns(b)) // B now owns it for real + assertFalse(coordinator.owns(a)) + } + + /** The single highest-value line in the coordinator: an app that disconnects must not keep ERG + * hostage. Nothing else covers it — trainerDropped() masks it in the broader ownership test. */ + @Test fun aDepartedOwnerDoesNotKeepControlHostage() { + val coordinator = FtmsControlCoordinator() + val a = coordinator.connected("A") + val b = coordinator.connected("B") + coordinator.admit("A", 0x00, null) + coordinator.response(0x00, FtmsControlCoordinator.SUCCESS) + assertTrue(coordinator.owns(a)) + + assertNull(coordinator.disconnected("A")) // nothing was pending, so no recycle + assertFalse(coordinator.owns(a)) // ...but ownership is gone with the connection + assertEquals(b, admitted(coordinator.admit("B", 0x00, null)).client) + assertEquals(b, coordinator.response(0x00, FtmsControlCoordinator.SUCCESS)?.client) + } + + @Test fun trainerWriteCompletesExactlyOnce() { + val results = mutableListOf() + val ticket = TrainerWriteTicket(7L) { results += it } + assertTrue(ticket.complete(true)) + assertFalse(ticket.complete(false)) + assertEquals(listOf(true), results) + } + + @Test fun targetResistanceUsesSigned16LittleEndian() { + assertArrayEquals(byteArrayOf(0x04, 0x24, 0x00), encodeTargetResistance(36)) + assertArrayEquals(byteArrayOf(0x04, 0x10, 0x00), encodeTargetResistance(16)) + // the high byte and the sign: 36/16 alone pass for byteArrayOf(0x04, v.toByte(), 0) + assertArrayEquals(byteArrayOf(0x04, 0x2C, 0x01), encodeTargetResistance(300)) + assertArrayEquals(byteArrayOf(0x04, 0xFF.toByte(), 0xFF.toByte()), encodeTargetResistance(-1)) + assertArrayEquals(byteArrayOf(0x04, 0x00, 0x80.toByte()), encodeTargetResistance(Int.MIN_VALUE)) + assertArrayEquals(byteArrayOf(0x04, 0xFF.toByte(), 0x7F), encodeTargetResistance(Int.MAX_VALUE)) + } + + // ── connect-attempt ownership (ZycleClient.connect / stop) ──────────────────────────────────── + /** An attempt invalidated while connectGatt() blocks must not publish its handle. NOT the `stopped` + * re-check between connect()'s first guard and replace() — that gap is closed by a plain field read in + * ZycleClient, which no coordinator-level test can reach (see the class KDoc). */ + @Test fun anInvalidatedConnectAttemptCannotPublishItsHandle() { + val attempts = IdentityOwner() + var published: String? = null + val attempt = Any() + + attempts.replace(attempt) // connect() registers... + attempts.clear() // ...stop() invalidates it while connectGatt blocks + assertFalse(attempts.clearIfCurrent(attempt) { published = "handle" }) + assertNull(published) + } + + /** A stale attempt returning after a newer one is live must close only its own handle: clearing the + * shared `connecting` latch there let a scan result start a third connection behind the live one. */ + @Test fun aStaleConnectAttemptTouchesNothingBelongingToItsReplacement() { + val attempts = IdentityOwner() + val stale = Any() + val live = Any() + var published: Any? = null + + attempts.replace(stale) + attempts.replace(live) // stop() + a later start() promoted a new attempt + assertFalse(attempts.clearIfCurrent(stale) { published = stale }) + assertNull(published) + // the live attempt still owns the outcome, so IT can still publish + assertTrue(attempts.clearIfCurrent(live) { published = live }) + assertEquals(live, published) + } + + // ── emit ownership (BridgeService.toZycle / stopEmit) ───────────────────────────────────────── + @Test fun controllableFtmsRequiresFeatureControlPointAndOnePowerStream() { + val readiness = FtmsBootstrapReadiness(controllable = true) + + assertFalse(readiness.ready) + assertEquals( + listOf( + "FTMS Feature read", + "FTMS Control Point subscription", + "Indoor Bike or Cycling Power subscription", + ), + readiness.missingRequirements, + ) + readiness.featureRead = true + assertFalse(readiness.ready) + assertEquals( + listOf("FTMS Control Point subscription", "Indoor Bike or Cycling Power subscription"), + readiness.missingRequirements, + ) + readiness.controlPointSubscribed = true + assertFalse(readiness.ready) + assertEquals(listOf("Indoor Bike or Cycling Power subscription"), readiness.missingRequirements) + readiness.indoorBikeSubscribed = true + assertTrue(readiness.ready) + assertTrue(readiness.missingRequirements.isEmpty()) + } + + @Test fun eitherIndoorBikeOrCyclingPowerSubscriptionSatisfiesPower() { + val indoorBike = FtmsBootstrapReadiness(controllable = true).apply { + featureRead = true + controlPointSubscribed = true + indoorBikeSubscribed = true + } + val cyclingPower = FtmsBootstrapReadiness(controllable = true).apply { + featureRead = true + controlPointSubscribed = true + cyclingPowerSubscribed = true + } + + assertTrue(indoorBike.ready) + assertTrue(cyclingPower.ready) + } + + @Test fun readOnlyProfileDoesNotRequireControlPoint() { + val readiness = FtmsBootstrapReadiness(controllable = false).apply { + indoorBikeSubscribed = true + } + + assertTrue(readiness.ready) + } + + @Test fun staleServiceAddCallbackCannotCompleteReplacementAttempt() { + val attempts = IdentityOwner() + val staleService = Any() + val replacementService = Any() + var completed: Any? = null + attempts.replace(staleService) + attempts.replace(replacementService) + + assertFalse(attempts.clearIfCurrent(staleService) { completed = staleService }) + assertNull(completed) + assertTrue(attempts.clearIfCurrent(replacementService) { completed = replacementService }) + assertEquals(replacementService, completed) + } + + /** The point of the emit token: a write admitted by the OLD mirror must never capture the NEW source. */ + @Test fun aStaleMirrorWriteCannotCaptureTheReplacementSource() { + val emitOwner = IdentityOwner() + val oldToken = Any() + emitOwner.replace(oldToken) + + var captured: String? = null + var mutated = false + assertTrue(emitOwner.runIfCurrent(oldToken) { mutated = true; captured = "old source" }) + assertEquals("old source", captured) + // stopEmit()'s barrier hands back exactly the token it retired. + assertEquals(oldToken, emitOwner.clear()) + emitOwner.replace(Any()) // startEmit() with a replacement source + captured = null; mutated = false + assertFalse(emitOwner.runIfCurrent(oldToken) { mutated = true; captured = "new source" }) + assertNull(captured) // never reached the replacement + assertFalse(mutated) // and left ErgBias/lastControl alone + } + + + @Test fun gattOperationTimeoutResetsClosesAndReconnectsWithoutPumping() { + val effects = mutableListOf() + val coordinator = GattSessionCoordinator( + resetRuntime = { effects += "reset" }, + disconnect = { effects += "disconnect" }, + close = { effects += "close" }, + reconnect = { effects += "reconnect" }, + ) + val session = Any() + coordinator.replace(session) + + assertTrue(coordinator.timeoutIfCurrent(session, stillPending = { true })) + assertEquals(listOf("reset", "disconnect", "close", "reconnect"), effects) + assertNull(coordinator.current) + } + + @Test fun staleGattTimeoutCannotRetireReplacementSession() { + var retirements = 0 + val coordinator = GattSessionCoordinator( + resetRuntime = { retirements++ }, disconnect = {}, close = {}, reconnect = {}, + ) + val stale = Any() + val replacement = Any() + coordinator.replace(stale) + coordinator.replace(replacement) + + assertFalse(coordinator.timeoutIfCurrent(stale, stillPending = { true })) + assertEquals(0, retirements) + assertTrue(coordinator.runIfCurrent(replacement) {}) + } + + @Test fun advertisingFailureStopsRegistrationBeforeStateAndRetryWhileStaleFailureIsNoOp() { + val attempts = AdvertisingAttemptCoordinator() + val firstCallback = Any() + val retryCallback = Any() + val effects = mutableListOf() + attempts.begin(firstCallback) { effects += "unexpected" } + + assertTrue(attempts.failIfCurrent( + firstCallback, + stop = { effects += "stop" }, + markFailed = { effects += "failed" }, + retry = { effects += "retry" }, + )) + attempts.begin(retryCallback) { effects += "retire-before-begin" } + assertEquals(listOf("stop", "failed", "retry"), effects) + assertFalse(attempts.failIfCurrent( + firstCallback, + stop = { effects += "stale stop" }, + markFailed = { effects += "stale failure" }, + retry = { effects += "stale retry" }, + )) + assertEquals(listOf("stop", "failed", "retry"), effects) + } + + @Test fun sourceTeardownCannotOvertakeAnAdmittedValueMutation() { + val owner = IdentityOwner() + val source = Any() + owner.replace(source) + val mutationEntered = CountDownLatch(1) + val releaseMutation = CountDownLatch(1) + val teardownEntered = CountDownLatch(1) + var state = "initial" + + val callback = thread { + owner.runIfCurrent(source) { + mutationEntered.countDown() + releaseMutation.await() + state = "old value" + } + } + assertTrue(mutationEntered.await(1, TimeUnit.SECONDS)) + val teardown = thread { + owner.clearIfCurrent(source) { + teardownEntered.countDown() + state = "stopped" + } + } + + assertFalse(teardownEntered.await(1, TimeUnit.SECONDS)) + releaseMutation.countDown() + callback.join(1_000) + teardown.join(1_000) + assertEquals("stopped", state) + assertFalse(owner.runIfCurrent(source) { state = "late value" }) + assertEquals("stopped", state) + } + + @Test fun ergPersistenceInvokesLearnerAndFlushesPendingAfterConvergence() { + var learnerCalls = 0 + val persistence = ErgBiasPersistence(persistIntervalMs = 60_000L) { _, _ -> + learnerCalls++ + when (learnerCalls) { 1 -> 7; 2 -> 8; else -> null } + } + + assertEquals(7, persistence.onPower(rawWatts = 157, nowMs = 10L)) + assertEquals(null, persistence.onPower(rawWatts = 158, nowMs = 1_000L)) + assertEquals(null, persistence.onPower(rawWatts = 158, nowMs = 30_000L)) + assertEquals(8, persistence.onPower(rawWatts = 158, nowMs = 60_010L)) + assertEquals(4, learnerCalls) + } +} diff --git a/app/src/test/java/com/enderthor/trainerbridgeble/correction/ErgBiasTest.kt b/app/src/test/java/com/enderthor/trainerbridgeble/correction/ErgBiasTest.kt new file mode 100644 index 0000000..2d8775a --- /dev/null +++ b/app/src/test/java/com/enderthor/trainerbridgeble/correction/ErgBiasTest.kt @@ -0,0 +1,98 @@ +package com.enderthor.trainerbridgeble.correction + +import org.junit.Assert.assertEquals +import org.junit.Assert.assertTrue +import org.junit.Before +import org.junit.Test + +class ErgBiasTest { + + /** ErgBias is a singleton — every test starts from a known state. */ + @Before fun reset() { ErgBias.seed(0); ErgBias.forget() } + + private fun setTargetPower(w: Int) = byteArrayOf(0x05, (w and 0xFF).toByte(), ((w shr 8) and 0xFF).toByte()) + + /** Feed `seconds` of a trainer that settles `overshoot` W above whatever it is commanded. */ + private fun ride(commandedRaw: Int, overshoot: Int, seconds: Int, startMs: Long = 0L): Long { + ErgBias.onControl(setTargetPower(commandedRaw), startMs) + var t = startMs + repeat(seconds) { t += 2_000; ErgBias.onPower(commandedRaw + overshoot, t) } + return t + } + + @Test fun learnsTheTrainersOvershoot() { + ride(commandedRaw = 150, overshoot = 8, seconds = 400) + assertEquals(8, ErgBias.watts) + } + + /** + * The property the whole design rests on: the bias converges on the trainer's error and STAYS there, + * because commanding lower does not change the error we sample. An error integrator would run away. + */ + @Test fun doesNotWindUpOnceApplied() { + val c = PowerCorrection(scale = 1.05, offset = 24.0, ergBiasW = 8) + val target = 200 + val commanded = c.invert(target) // already 8 W lower than the honest inverse + ride(commandedRaw = commanded, overshoot = 8, seconds = 600) + assertEquals(8, ErgBias.watts) // still 8 — not 16, not climbing + // ...and the rider gets what the app asked for: the trainer delivers commanded + 8. + assertEquals(target, c.correct(commanded + 8)) + } + + /** + * Regression: subtracting the bias BEFORE the "is the app asking for nothing" check widened that + * window by the bias, so a 30 W recovery target commanded 0 — flywheel free — instead of holding the + * ERG floor. The bias may push the command down, never past the floor and never off a cliff to zero. + */ + @Test fun theErgBiasNeverCostsTheFloor() { + val plain = PowerCorrection(scale = 1.08, offset = 25.0, invertFloorW = 50) + val biased = PowerCorrection(scale = 1.08, offset = 25.0, invertFloorW = 50, ergBiasW = 8) + for (target in 1..400) { + val p = plain.invert(target); val b = biased.invert(target) + if (p == 0) assertEquals("target $target: zero must stay zero", 0, b) + else assertTrue("target $target: floor lost ($p -> $b)", b >= 23) // floorRaw = (50-25)/1.08 + } + assertEquals(0, biased.invert(25)) // within the offset: still a real stop + assertEquals(23, biased.invert(30)) // recovery target: still holds the floor + assertEquals(154, biased.invert(200)) // well above it: the full bias applies + } + + @Test fun ignoresTheRampToANewTarget() { + ErgBias.onControl(setTargetPower(150), 0L) + repeat(5) { ErgBias.onPower(60, 2_000L * it) } // first 10 s: still spinning up, way under target + assertEquals(0, ErgBias.watts) + } + + @Test fun ignoresACoastingRiderAndLowTargets() { + ErgBias.onControl(setTargetPower(150), 0L) + repeat(100) { ErgBias.onPower(0, 20_000L + 2_000L * it) } // stopped pedalling + assertEquals(0, ErgBias.watts) + ride(commandedRaw = 20, overshoot = 15, seconds = 200) // below the ERG floor: means nothing + assertEquals(0, ErgBias.watts) + } + + @Test fun stopEndsTheMeasurement() { + ErgBias.onControl(setTargetPower(150), 0L) + ErgBias.onControl(byteArrayOf(0x08), 1_000L) // FTMS Stop/Pause + repeat(200) { ErgBias.onPower(300, 20_000L + 2_000L * it) } + assertEquals(0, ErgBias.watts) + } + + @Test fun oneAbsurdSampleBarelyMovesIt() { + ride(commandedRaw = 150, overshoot = 8, seconds = 400) + ErgBias.onPower(150 + 900, 2_000_000L) // a garbage frame / standing sprint + assertTrue("a single outlier must not swing the bias", ErgBias.watts in 8..10) + } + + @Test fun staysWithinItsClamp() { + ride(commandedRaw = 150, overshoot = 500, seconds = 2000) + assertEquals(30, ErgBias.watts) + } + + @Test fun seedSurvivesUntilNewEvidence() { + ErgBias.seed(9) + assertEquals(9, ErgBias.watts) + ErgBias.forget() + assertEquals(9, ErgBias.watts) // the trainer dropping does not unlearn the trainer + } +}