Stop the scanner throttling itself off the air
Android counts an app's scan *starts*: five in any thirty seconds and the platform answers `SCAN_FAILED_SCANNING_TOO_FREQUENTLY` and stops returning results. It does this silently as far as btleplug is concerned, so the app goes on asking and simply stops being told about anything. `scan_loop` opened a session every 2.9 s — a 2.5 s window plus 400 ms idle. **Ten starts per thirty seconds, twice the limit, with nothing else running.** Add the trainer's 15 s search or a pod's 20 s one, which `click.rs` notes runs to the full timeout because a Click only advertises after a button press, and the app spends much of its life muted. A rider who wakes the pods first is doing exactly the thing that pushes the count over, and then the trainer cannot be found — not because it is not advertising, but because the app is no longer allowed to hear it. Starting a scan is the expensive act, not running one, so hold the session and sample it: - scan.rs splits `scan` into `begin` / `peek` / `end`, sharing one describe-filter-rank path (`collect`). `scan` stays as the one-shot form for the probe tool. - `scan_loop` opens one session per SCAN_WINDOW (now 20 s) and peeks every 700 ms, publishing each time. The radio starts a seventh as often and the list updates four times *quicker* than the old whole-pass cadence. - The session is recycled rather than held forever: a new adapter each cycle is what drops peripherals that have left the room, so 20 s is how stale a departed device may look. That was ~3 s before, and it is the one thing this trade gives up. - The sample loop selects on the scan switch, so a suspension still lands immediately. A connect suspends this loop precisely so the two do not fight over the radio, and a suspension that took twenty seconds to arrive would be no suspension at all. Instrumented at the choke point every caller passes through, because "the radio is busy" and "the peripheral is asleep" look identical from outside: every session start logs the concurrent depth and how many starts there have been in the last thirty seconds, and warns when either number is a problem. Measured on the tablet after this change — one start per ~21 s, `recent=2`, against a limit of five. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
+117
-8
@@ -1,7 +1,9 @@
|
|||||||
//! BLE discovery (FR-1.1, FR-1.2).
|
//! BLE discovery (FR-1.1, FR-1.2).
|
||||||
|
|
||||||
use std::collections::HashMap;
|
use std::collections::{HashMap, VecDeque};
|
||||||
use std::time::Duration;
|
use std::sync::atomic::{AtomicUsize, Ordering};
|
||||||
|
use std::sync::Mutex;
|
||||||
|
use std::time::{Duration, Instant};
|
||||||
|
|
||||||
use btleplug::api::{Central, Manager as _, Peripheral as _, ScanFilter};
|
use btleplug::api::{Central, Manager as _, Peripheral as _, ScanFilter};
|
||||||
use btleplug::platform::{Adapter, Manager, Peripheral, PeripheralId};
|
use btleplug::platform::{Adapter, Manager, Peripheral, PeripheralId};
|
||||||
@@ -114,24 +116,129 @@ impl ScanKind {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// How many discovery sessions this process currently has open.
|
||||||
|
///
|
||||||
|
/// The adapter has **one** radio, and four independent supervisors ask it to
|
||||||
|
/// discover: the device list (`devices::scan_loop`, a 2.5 s pass every ~2.9 s),
|
||||||
|
/// the trainer client (15 s), the controller (20 s per pod attempt, up to 30
|
||||||
|
/// attempts), and the heart rate monitor. Only the first two are coordinated —
|
||||||
|
/// `DeviceRegistry::connect` suspends the list scan for a trainer connect
|
||||||
|
/// precisely so the two do not fight (devices.rs) — and a pod search routinely
|
||||||
|
/// runs its full 20 s because a Click only advertises after a button press.
|
||||||
|
///
|
||||||
|
/// So this counts. Every start and stop below logs the depth and who is
|
||||||
|
/// holding it; a line reading `depth=2` names both competitors and is the
|
||||||
|
/// evidence that a failed connect was a contended radio rather than a sleeping
|
||||||
|
/// peripheral. Diagnostic only — nothing here changes what the radio does.
|
||||||
|
static DISCOVERY_DEPTH: AtomicUsize = AtomicUsize::new(0);
|
||||||
|
|
||||||
|
/// Android's rule, and the one this app kept breaking: five scan *starts* in
|
||||||
|
/// any thirty seconds and the platform stops returning results.
|
||||||
|
const THROTTLE_WINDOW: Duration = Duration::from_secs(30);
|
||||||
|
const THROTTLE_STARTS: usize = 5;
|
||||||
|
|
||||||
|
/// When each recent session was opened, for the rate check below.
|
||||||
|
static STARTS: Mutex<VecDeque<Instant>> = Mutex::new(VecDeque::new());
|
||||||
|
|
||||||
|
/// Announce a discovery session opening, and return the depth including it.
|
||||||
|
///
|
||||||
|
/// Logs two different problems, because they have different fixes: `depth > 1`
|
||||||
|
/// is two searches sharing one radio, and a start rate at the platform's limit
|
||||||
|
/// is the app about to be muted by Android whether or not anything is sharing.
|
||||||
|
fn discovery_opened(who: &str) -> usize {
|
||||||
|
let depth = DISCOVERY_DEPTH.fetch_add(1, Ordering::SeqCst) + 1;
|
||||||
|
|
||||||
|
let recent = {
|
||||||
|
let now = Instant::now();
|
||||||
|
let mut starts = STARTS.lock().unwrap_or_else(|e| e.into_inner());
|
||||||
|
while starts.front().is_some_and(|t| now.duration_since(*t) > THROTTLE_WINDOW) {
|
||||||
|
starts.pop_front();
|
||||||
|
}
|
||||||
|
starts.push_back(now);
|
||||||
|
starts.len()
|
||||||
|
};
|
||||||
|
|
||||||
|
if recent >= THROTTLE_STARTS {
|
||||||
|
tracing::warn!(
|
||||||
|
who,
|
||||||
|
recent,
|
||||||
|
depth,
|
||||||
|
"discovery: {recent} scan starts in the last 30 s — at Android's limit, \
|
||||||
|
where further scans return nothing at all"
|
||||||
|
);
|
||||||
|
} else if depth > 1 {
|
||||||
|
tracing::warn!(
|
||||||
|
who,
|
||||||
|
depth,
|
||||||
|
recent,
|
||||||
|
"discovery: sharing the radio with another search — connects may time out"
|
||||||
|
);
|
||||||
|
} else {
|
||||||
|
tracing::debug!(who, depth, recent, "discovery: start");
|
||||||
|
}
|
||||||
|
depth
|
||||||
|
}
|
||||||
|
|
||||||
|
fn discovery_closed(who: &str, outcome: &str) {
|
||||||
|
let depth = DISCOVERY_DEPTH.fetch_sub(1, Ordering::SeqCst).saturating_sub(1);
|
||||||
|
tracing::debug!(who, depth, outcome, "discovery: stop");
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Open a discovery session and leave it open.
|
||||||
|
///
|
||||||
|
/// Paired with [`end`], and sampled meanwhile with [`peek`]. The three exist
|
||||||
|
/// separately because **starting a scan is the expensive act on Android**, not
|
||||||
|
/// running one: since Android 7 the platform counts an app's scan *starts* and
|
||||||
|
/// refuses it with `SCAN_FAILED_SCANNING_TOO_FREQUENTLY` after five in thirty
|
||||||
|
/// seconds — silently, as far as btleplug is concerned, so the app goes on
|
||||||
|
/// asking and simply stops being told about anything.
|
||||||
|
///
|
||||||
|
/// A caller that wants a live list therefore has to hold one session and
|
||||||
|
/// sample it, rather than restart one per refresh. See `devices::scan_loop`.
|
||||||
|
pub async fn begin(adapter: &Adapter, kind: ScanKind, who: &str) -> Result<(), FtmsError> {
|
||||||
|
adapter.start_scan(kind.filter()).await?;
|
||||||
|
discovery_opened(who);
|
||||||
|
Ok(())
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Everything the open session has seen so far. Does not touch the session.
|
||||||
|
pub async fn peek(adapter: &Adapter, kind: ScanKind) -> Result<Vec<DiscoveredDevice>, FtmsError> {
|
||||||
|
let peripherals = adapter.peripherals().await?;
|
||||||
|
Ok(collect(peripherals, kind).await)
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Close a session opened by [`begin`]. Best effort: a failure to stop is worth
|
||||||
|
/// a line in the log and nothing more, since the next start subsumes it.
|
||||||
|
pub async fn end(adapter: &Adapter, who: &str, outcome: &str) {
|
||||||
|
if let Err(e) = adapter.stop_scan().await {
|
||||||
|
tracing::debug!(error = %e, "stop_scan failed");
|
||||||
|
}
|
||||||
|
discovery_closed(who, outcome);
|
||||||
|
}
|
||||||
|
|
||||||
/// Scan for `duration` and return everything seen.
|
/// Scan for `duration` and return everything seen.
|
||||||
///
|
///
|
||||||
/// Devices may be asleep (A-4) — a trainer often does not advertise until it is
|
/// Devices may be asleep (A-4) — a trainer often does not advertise until it is
|
||||||
/// pedalled. An empty result means "nothing was advertising", not "no such
|
/// pedalled. An empty result means "nothing was advertising", not "no such
|
||||||
/// device exists"; FR-1.8 requires the UI to say so.
|
/// device exists"; FR-1.8 requires the UI to say so.
|
||||||
|
///
|
||||||
|
/// One session per call, so this is for one-shot callers — the probe tool, a
|
||||||
|
/// test. Anything refreshing on a timer wants [`begin`]/[`peek`]/[`end`].
|
||||||
pub async fn scan(
|
pub async fn scan(
|
||||||
adapter: &Adapter,
|
adapter: &Adapter,
|
||||||
duration: Duration,
|
duration: Duration,
|
||||||
kind: ScanKind,
|
kind: ScanKind,
|
||||||
) -> Result<Vec<DiscoveredDevice>, FtmsError> {
|
) -> Result<Vec<DiscoveredDevice>, FtmsError> {
|
||||||
adapter.start_scan(kind.filter()).await?;
|
begin(adapter, kind, "device list").await?;
|
||||||
tokio::time::sleep(duration).await;
|
tokio::time::sleep(duration).await;
|
||||||
let peripherals = adapter.peripherals().await?;
|
let peripherals = adapter.peripherals().await?;
|
||||||
// Stopping the scan is best effort; a failure here must not lose results.
|
end(adapter, "device list", "listed").await;
|
||||||
if let Err(e) = adapter.stop_scan().await {
|
|
||||||
tracing::debug!(error = %e, "stop_scan failed");
|
|
||||||
}
|
|
||||||
|
|
||||||
|
Ok(collect(peripherals, kind).await)
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Describe, filter and rank what the radio handed back.
|
||||||
|
async fn collect(peripherals: Vec<Peripheral>, kind: ScanKind) -> Vec<DiscoveredDevice> {
|
||||||
let mut out = Vec::with_capacity(peripherals.len());
|
let mut out = Vec::with_capacity(peripherals.len());
|
||||||
for p in peripherals {
|
for p in peripherals {
|
||||||
if let Some(d) = describe(&p).await {
|
if let Some(d) = describe(&p).await {
|
||||||
@@ -143,7 +250,7 @@ pub async fn scan(
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
out.sort_by(|a, b| b.rssi.unwrap_or(i16::MIN).cmp(&a.rssi.unwrap_or(i16::MIN)));
|
out.sort_by(|a, b| b.rssi.unwrap_or(i16::MIN).cmp(&a.rssi.unwrap_or(i16::MIN)));
|
||||||
Ok(out)
|
out
|
||||||
}
|
}
|
||||||
|
|
||||||
/// Convenience wrapper: scan the default adapter for trainers.
|
/// Convenience wrapper: scan the default adapter for trainers.
|
||||||
@@ -261,6 +368,7 @@ pub async fn find_matching(
|
|||||||
matches: impl Fn(&DiscoveredDevice) -> bool,
|
matches: impl Fn(&DiscoveredDevice) -> bool,
|
||||||
) -> Result<Peripheral, FtmsError> {
|
) -> Result<Peripheral, FtmsError> {
|
||||||
adapter.start_scan(kind.filter()).await?;
|
adapter.start_scan(kind.filter()).await?;
|
||||||
|
discovery_opened(what);
|
||||||
|
|
||||||
let deadline = tokio::time::Instant::now() + timeout;
|
let deadline = tokio::time::Instant::now() + timeout;
|
||||||
let poll = Duration::from_millis(400);
|
let poll = Duration::from_millis(400);
|
||||||
@@ -291,6 +399,7 @@ pub async fn find_matching(
|
|||||||
if let Err(e) = adapter.stop_scan().await {
|
if let Err(e) = adapter.stop_scan().await {
|
||||||
tracing::debug!(error = %e, "stop_scan failed");
|
tracing::debug!(error = %e, "stop_scan failed");
|
||||||
}
|
}
|
||||||
|
discovery_closed(what, if found.is_some() { "matched" } else { "timed out" });
|
||||||
|
|
||||||
found.ok_or_else(|| FtmsError::NotFound(what.to_string()))
|
found.ok_or_else(|| FtmsError::NotFound(what.to_string()))
|
||||||
}
|
}
|
||||||
|
|||||||
+83
-24
@@ -35,9 +35,27 @@ use crate::heart_rate::{HeartRateHandle, HeartRateStatus};
|
|||||||
use crate::known::KnownDevices;
|
use crate::known::KnownDevices;
|
||||||
use crate::trainer::{TrainerHandle, TrainerStatus};
|
use crate::trainer::{TrainerHandle, TrainerStatus};
|
||||||
|
|
||||||
/// One pass of the scanner. Long enough for a trainer to advertise, short
|
/// How long one discovery session is held before it is recycled.
|
||||||
/// enough that the list feels live.
|
///
|
||||||
const SCAN_WINDOW: Duration = Duration::from_millis(2500);
|
/// **This is a rate limit, not a dwell time.** Since Android 7 the platform
|
||||||
|
/// counts an app's scan *starts* and blocks it with
|
||||||
|
/// `SCAN_FAILED_SCANNING_TOO_FREQUENTLY` after five in any thirty seconds — and
|
||||||
|
/// it does so silently, so the app keeps asking and simply stops being told
|
||||||
|
/// about anything. This loop used to open a session every 2.9 s: **ten starts
|
||||||
|
/// per thirty seconds, double the limit, all by itself**, before the trainer's
|
||||||
|
/// 15 s search or a pod's 20 s search asked for one too. A rider who woke their
|
||||||
|
/// pods first spent the pods' search window pushing the count over, and then
|
||||||
|
/// the trainer could not be found — not because it was not advertising, but
|
||||||
|
/// because the app was no longer allowed to hear it.
|
||||||
|
///
|
||||||
|
/// One session per twenty seconds is three starts a minute with the connect
|
||||||
|
/// paths included, which leaves headroom under the limit on the worst day.
|
||||||
|
const SCAN_WINDOW: Duration = Duration::from_secs(20);
|
||||||
|
/// How often the open session is sampled. The list is republished each time, so
|
||||||
|
/// this — not [`SCAN_WINDOW`] — is how live the screen feels, and it is now
|
||||||
|
/// four times quicker than the old whole-pass cadence while starting the radio
|
||||||
|
/// a seventh as often.
|
||||||
|
const SCAN_SAMPLE: Duration = Duration::from_millis(700);
|
||||||
/// Poll interval while scanning is switched off.
|
/// Poll interval while scanning is switched off.
|
||||||
const IDLE_POLL: Duration = Duration::from_millis(400);
|
const IDLE_POLL: Duration = Duration::from_millis(400);
|
||||||
/// How long to wait before looking for the adapter again. Longer than the scan
|
/// How long to wait before looking for the adapter again. Longer than the scan
|
||||||
@@ -897,30 +915,71 @@ async fn scan_loop(mut on: watch::Receiver<bool>, tx: watch::Sender<ScanSnapshot
|
|||||||
// FR-1.1 lists every peripheral, not only fitness machines: a trainer
|
// FR-1.1 lists every peripheral, not only fitness machines: a trainer
|
||||||
// is not obliged to advertise FTMS, and the rider needs to see what is
|
// is not obliged to advertise FTMS, and the rider needs to see what is
|
||||||
// in the room to know the scan is working at all.
|
// in the room to know the scan is working at all.
|
||||||
let result = scan::scan(&adapter, SCAN_WINDOW, ScanKind::All).await;
|
if let Err(e) = scan::begin(&adapter, ScanKind::All, "device list").await {
|
||||||
generation += 1;
|
// Debug as well as Display, because the useful half of a BLE
|
||||||
let snapshot = match result {
|
// failure is usually in the source chain that Display drops.
|
||||||
Ok(devices) => ScanSnapshot {
|
// "bluetooth error: JNI call failed" was the *entire* symptom of a
|
||||||
devices,
|
// detached-thread bug; the Debug form said
|
||||||
error: None,
|
// `Bluetooth(Other(JniCall(ThreadDetached)))` and would have named
|
||||||
|
// it outright.
|
||||||
|
tracing::warn!(error = %e, cause = ?e, "scan failed to start");
|
||||||
|
generation += 1;
|
||||||
|
let _ = tx.send(ScanSnapshot {
|
||||||
|
devices: Vec::new(),
|
||||||
|
error: Some(e.to_string()),
|
||||||
generation,
|
generation,
|
||||||
},
|
});
|
||||||
Err(e) => {
|
tokio::time::sleep(ADAPTER_RETRY).await;
|
||||||
// Debug as well as Display, because the useful half of a BLE
|
continue;
|
||||||
// failure is usually in the source chain that Display drops.
|
}
|
||||||
// "bluetooth error: JNI call failed" was the *entire* symptom of
|
|
||||||
// a detached-thread bug; the Debug form said
|
// Sample the open session until the window is up — or until the scan is
|
||||||
// `Bluetooth(Other(JniCall(ThreadDetached)))` and would have
|
// switched off, which must be honoured *now* rather than at the end of
|
||||||
// named it outright.
|
// the window. A connect suspends this loop precisely so the two do not
|
||||||
tracing::warn!(error = %e, cause = ?e, "scan failed");
|
// fight over the radio, and a suspension that took twenty seconds to
|
||||||
ScanSnapshot {
|
// land would be no suspension at all.
|
||||||
devices: Vec::new(),
|
let window_ends = tokio::time::Instant::now() + SCAN_WINDOW;
|
||||||
error: Some(e.to_string()),
|
let mut outcome = "recycled";
|
||||||
generation,
|
loop {
|
||||||
|
tokio::select! {
|
||||||
|
_ = tokio::time::sleep(SCAN_SAMPLE) => {}
|
||||||
|
changed = on.changed() => {
|
||||||
|
if changed.is_err() || !*on.borrow() {
|
||||||
|
outcome = "suspended";
|
||||||
|
break;
|
||||||
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
};
|
generation += 1;
|
||||||
let _ = tx.send(snapshot);
|
match scan::peek(&adapter, ScanKind::All).await {
|
||||||
|
Ok(devices) => {
|
||||||
|
let _ = tx.send(ScanSnapshot {
|
||||||
|
devices,
|
||||||
|
error: None,
|
||||||
|
generation,
|
||||||
|
});
|
||||||
|
}
|
||||||
|
Err(e) => {
|
||||||
|
tracing::warn!(error = %e, cause = ?e, "scan sample failed");
|
||||||
|
let _ = tx.send(ScanSnapshot {
|
||||||
|
devices: Vec::new(),
|
||||||
|
error: Some(e.to_string()),
|
||||||
|
generation,
|
||||||
|
});
|
||||||
|
outcome = "failed";
|
||||||
|
break;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
if tokio::time::Instant::now() >= window_ends {
|
||||||
|
break;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// Recycled rather than held forever: a peripheral that stops
|
||||||
|
// advertising stays in the backend's map until the session ends, so
|
||||||
|
// without this the list would accumulate devices that left the room.
|
||||||
|
// Twenty seconds is how stale a departed device may look.
|
||||||
|
scan::end(&adapter, "device list", outcome).await;
|
||||||
tokio::time::sleep(IDLE_POLL).await;
|
tokio::time::sleep(IDLE_POLL).await;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user