Make the BLE layer say what it actually received
Chasing a paddle that shifted on one platform and not the other cost several rebuilds, and most of that was spent unable to tell two very different situations apart: a pod that was sending nothing, and a pod whose frames we were receiving and quietly discarding. The logs looked identical because every decoder in this path fails by dropping. `click.rs` now logs every notification with its length and bytes before anything tries to interpret it, and the unhandled-frame line in `controller.rs` carries the payload rather than just the type byte — which is the least useful part of a frame you could not parse, since it is usually the framing that is wrong and not the content. The default log filter gains `bikecontrol_ble=debug`. It was `info`, which silenced the entire crate that owns every BLE conversation — subscribe failures included. Survivable on desktop where RUST_LOG can override it; not on Android, which has no environment to set and is exactly where the subscribe was failing. Adds `probe listen`, which decodes nothing on purpose: the GATT tree with descriptors (the CCCD value is where a subscribe goes wrong, and `inspect` stops short of it), then a subscribe to every notifying characteristic across all services, reporting each as ok or FAILED. Each notification prints characteristic, length and raw bytes, and the summary names the characteristics that stayed silent — the difference between a quiet device and listening in the wrong place. That last part is what settled this one: it recorded 304 button frames from a pod the app was reporting as dead. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
Claude Opus 5
@@ -26,6 +26,7 @@ use tokio::sync::{broadcast, mpsc, oneshot};
|
||||
|
||||
use crate::client::{Backoff, InFlight, DISCONNECT_TIMEOUT};
|
||||
use crate::error::FtmsError;
|
||||
use crate::indoor_bike_data::hex;
|
||||
use crate::scan::{self, ScanKind};
|
||||
use crate::zwift::{self, Button, ButtonTracker, PodId};
|
||||
|
||||
@@ -541,6 +542,12 @@ impl Actor {
|
||||
|
||||
/// Decode one notification into events.
|
||||
fn handle(&mut self, raw: &[u8]) {
|
||||
// Every frame, before anything decides what it means (NFR-8). The
|
||||
// decoders below all fail by dropping, so without this a pod that is
|
||||
// talking and a pod that is silent produce identical logs — which is
|
||||
// exactly the ambiguity that made a working paddle look like dead
|
||||
// hardware.
|
||||
tracing::debug!(len = raw.len(), raw = %hex(raw), "click: frame");
|
||||
if zwift::is_ride_on_reply(raw) {
|
||||
tracing::debug!("click: RideOn acknowledged");
|
||||
return;
|
||||
|
||||
+25
-1
@@ -21,6 +21,9 @@ SUBCOMMANDS:
|
||||
monitor <ADDR> Stream Indoor Bike Data as raw hex alongside decoded fields
|
||||
set <ADDR> <TARGET> Take control and apply a target, then reset the trainer to zero
|
||||
zwift <ADDR> Talk to Zwift's custom service: handshake, then log every frame
|
||||
listen <ADDR> Raw GATT: dump services, characteristics and descriptors, then
|
||||
subscribe to everything and print each notification's
|
||||
characteristic, length and bytes, undecoded
|
||||
|
||||
TARGET (for `set`):
|
||||
gradient=<PCT> SetTargetInclination (0x03), e.g. gradient=4.5
|
||||
@@ -33,7 +36,9 @@ OPTIONS:
|
||||
scan 6, monitor 30, set 15, zwift 60)
|
||||
--all `scan`: list every peripheral, not just fitness machines
|
||||
--name <SUBSTR> use in place of <ADDR> to match on advertised name
|
||||
--no-handshake `zwift`: subscribe and listen without writing RideOn
|
||||
--no-handshake `zwift`, `listen`: subscribe and listen without writing RideOn.
|
||||
`listen` greets by default, because a Click that has not been
|
||||
greeted sends nothing and an empty capture proves nothing
|
||||
--buttons `zwift`: collapse the ~10 Hz button stream to one line per
|
||||
press and release, for mapping bits to physical buttons
|
||||
-v, --verbose debug-level logging, including every raw BLE frame (NFR-8)
|
||||
@@ -70,6 +75,20 @@ pub enum Command {
|
||||
simulation: bool,
|
||||
hold: Duration,
|
||||
},
|
||||
/// Raw GATT interrogation: the whole tree including descriptors, then every
|
||||
/// notifying characteristic dumped as unparsed bytes.
|
||||
///
|
||||
/// Deliberately knows nothing about FTMS or Zwift. When a device works on
|
||||
/// one platform and not another, the question is which characteristic
|
||||
/// carried what and how long it was — and any decoding layer is exactly
|
||||
/// what you cannot trust while asking it.
|
||||
Listen {
|
||||
device: Device,
|
||||
duration: Duration,
|
||||
/// Write the Zwift `RideOn` handshake first. A Click streams nothing
|
||||
/// until it is greeted, so listening alone hears silence from one.
|
||||
handshake: bool,
|
||||
},
|
||||
/// Phase 3 / TASK-0: exercise Zwift's custom service on whatever advertises
|
||||
/// it — a Click, or the trainer itself.
|
||||
Zwift {
|
||||
@@ -190,6 +209,11 @@ pub fn parse<I: IntoIterator<Item = String>>(argv: I) -> Result<Args> {
|
||||
hold: Duration::from_secs(secs.unwrap_or(15)),
|
||||
}
|
||||
}
|
||||
"listen" => Command::Listen {
|
||||
device: device(&positional, 1)?,
|
||||
duration: Duration::from_secs(secs.unwrap_or(60)),
|
||||
handshake: !no_handshake,
|
||||
},
|
||||
"zwift" => Command::Zwift {
|
||||
device: device(&positional, 1)?,
|
||||
duration: Duration::from_secs(secs.unwrap_or(60)),
|
||||
|
||||
@@ -1131,3 +1131,185 @@ mod tests {
|
||||
assert_eq!(properties(CharPropFlags::empty()), "(none)");
|
||||
}
|
||||
}
|
||||
|
||||
// ---------------------------------------------------------------------------
|
||||
// listen
|
||||
// ---------------------------------------------------------------------------
|
||||
|
||||
/// Raw GATT interrogation, with no idea what any of it means.
|
||||
///
|
||||
/// Every other subcommand decodes something. This one deliberately does not:
|
||||
/// it prints the tree, subscribes to everything that will have it, and reports
|
||||
/// each notification as a characteristic, a length and some bytes.
|
||||
///
|
||||
/// That combination is what a cross-platform disagreement needs. When a device
|
||||
/// behaves on one backend and not another, the useful questions are *which*
|
||||
/// characteristic carried the data and *how many bytes arrived* — and a decoder
|
||||
/// answers neither, because its failure mode is to drop the frame silently and
|
||||
/// leave you looking at nothing. A length printed next to a truncated payload
|
||||
/// says more than a parse error ever does.
|
||||
pub async fn listen(
|
||||
device: &Device,
|
||||
duration: Duration,
|
||||
do_handshake: bool,
|
||||
scan_timeout: Duration,
|
||||
) -> Result<()> {
|
||||
let peripheral = connect(device, scan_timeout).await?;
|
||||
|
||||
if let Some(d) = scan::describe(&peripheral).await {
|
||||
println!("Connected to {} ({})", d.address, d.label());
|
||||
if let Some(kind) = d.zwift_kind() {
|
||||
println!("Advertised as: {}", kind.describe());
|
||||
}
|
||||
println!();
|
||||
}
|
||||
|
||||
// The whole tree first, so the capture below can be read months later
|
||||
// without the device to hand.
|
||||
println!("=== GATT tree ===\n");
|
||||
let mut notifying: Vec<Characteristic> = Vec::new();
|
||||
for service in peripheral.services() {
|
||||
println!(
|
||||
"service {}{}{}",
|
||||
service.uuid,
|
||||
named(service.uuid),
|
||||
if service.primary { " [primary]" } else { "" }
|
||||
);
|
||||
for ch in &service.characteristics {
|
||||
let subscribable = ch
|
||||
.properties
|
||||
.intersects(CharPropFlags::NOTIFY | CharPropFlags::INDICATE);
|
||||
println!(
|
||||
" char {}{}\n properties: {}{}",
|
||||
ch.uuid,
|
||||
named(ch.uuid),
|
||||
properties(ch.properties),
|
||||
if subscribable { " <- will subscribe" } else { "" }
|
||||
);
|
||||
// Descriptors are the part `inspect` omits, and the CCCD is exactly
|
||||
// where a subscribe goes wrong: its value says whether the platform
|
||||
// enabled notification, indication, or nothing at all.
|
||||
for d in &ch.descriptors {
|
||||
match peripheral.read_descriptor(d).await {
|
||||
Ok(v) => println!(
|
||||
" descriptor {}{} = {}",
|
||||
d.uuid,
|
||||
named(d.uuid),
|
||||
hex(&v)
|
||||
),
|
||||
Err(e) => println!(
|
||||
" descriptor {}{} <unreadable: {e}>",
|
||||
d.uuid,
|
||||
named(d.uuid)
|
||||
),
|
||||
}
|
||||
}
|
||||
if subscribable {
|
||||
notifying.push(ch.clone());
|
||||
}
|
||||
}
|
||||
println!();
|
||||
}
|
||||
|
||||
if notifying.is_empty() {
|
||||
println!("!! Nothing here notifies or indicates. There is nothing to listen to.");
|
||||
disconnect(&peripheral).await;
|
||||
return Ok(());
|
||||
}
|
||||
|
||||
let mut notifications = peripheral.notifications().await?;
|
||||
let start = Instant::now();
|
||||
|
||||
println!("=== Subscribing ===\n");
|
||||
let mut live = 0usize;
|
||||
for ch in ¬ifying {
|
||||
match peripheral.subscribe(ch).await {
|
||||
Ok(()) => {
|
||||
live += 1;
|
||||
println!(" ok {}{}", ch.uuid, named(ch.uuid));
|
||||
}
|
||||
// Reported rather than fatal: one characteristic refusing is itself
|
||||
// the finding, and the others may still carry what we came for.
|
||||
Err(e) => println!(" FAILED {}{} — {e}", ch.uuid, named(ch.uuid)),
|
||||
}
|
||||
}
|
||||
println!("\n{live} of {} subscribed.\n", notifying.len());
|
||||
|
||||
let mut frames: u64 = 0;
|
||||
if do_handshake {
|
||||
let service = zwift::SERVICES
|
||||
.iter()
|
||||
.find_map(|want| peripheral.services().into_iter().find(|s| s.uuid == *want));
|
||||
match service.as_ref().and_then(writable) {
|
||||
Some(sync_rx) => {
|
||||
frames += handshake(&peripheral, &sync_rx, &mut notifications, start).await?;
|
||||
}
|
||||
None => println!(
|
||||
"No writable Zwift characteristic — greeting skipped. A Click will stay\n\
|
||||
silent; anything that streams unprompted will not care.\n"
|
||||
),
|
||||
}
|
||||
} else {
|
||||
println!("--no-handshake: writing nothing.\n");
|
||||
}
|
||||
|
||||
println!(
|
||||
"Listening for {} s. Press buttons; Ctrl-C to stop early.\n",
|
||||
duration.saturating_sub(start.elapsed()).as_secs()
|
||||
);
|
||||
println!(" time # characteristic len bytes");
|
||||
|
||||
let deadline = tokio::time::sleep(duration.saturating_sub(start.elapsed()));
|
||||
tokio::pin!(deadline);
|
||||
|
||||
// Per characteristic, so a summary can show which ones ever spoke — the
|
||||
// difference between "the pod is silent" and "we were listening in the
|
||||
// wrong place".
|
||||
let mut counts: std::collections::BTreeMap<Uuid, (u64, usize)> = Default::default();
|
||||
|
||||
loop {
|
||||
tokio::select! {
|
||||
_ = &mut deadline => break,
|
||||
_ = tokio::signal::ctrl_c() => {
|
||||
println!("\nInterrupted.");
|
||||
break;
|
||||
}
|
||||
n = notifications.next() => {
|
||||
let Some(n) = n else {
|
||||
println!("\nNotification stream ended (the device disconnected).");
|
||||
break;
|
||||
};
|
||||
frames += 1;
|
||||
let entry = counts.entry(n.uuid).or_insert((0, 0));
|
||||
entry.0 += 1;
|
||||
entry.1 = entry.1.max(n.value.len());
|
||||
println!(
|
||||
" {:6.2}s #{:<4} {}{:<8} {:>3} {} {}",
|
||||
start.elapsed().as_secs_f32(),
|
||||
frames,
|
||||
n.uuid,
|
||||
named(n.uuid),
|
||||
n.value.len(),
|
||||
hex(&n.value),
|
||||
as_text(&n.value),
|
||||
);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
println!("\n=== {frames} frames ===\n");
|
||||
for (uuid, (count, longest)) in &counts {
|
||||
println!(" {uuid}{} {count} frames, longest {longest} bytes", named(*uuid));
|
||||
}
|
||||
for ch in ¬ifying {
|
||||
if !counts.contains_key(&ch.uuid) {
|
||||
println!(" {}{} silent", ch.uuid, named(ch.uuid));
|
||||
}
|
||||
}
|
||||
|
||||
for ch in ¬ifying {
|
||||
let _ = peripheral.unsubscribe(ch).await;
|
||||
}
|
||||
disconnect(&peripheral).await;
|
||||
Ok(())
|
||||
}
|
||||
|
||||
@@ -49,6 +49,11 @@ async fn main() -> Result<()> {
|
||||
simulation,
|
||||
hold,
|
||||
} => commands::set(&device, target, simulation, hold, SCAN_TIMEOUT).await,
|
||||
cli::Command::Listen {
|
||||
device,
|
||||
duration,
|
||||
handshake,
|
||||
} => commands::listen(&device, duration, handshake, SCAN_TIMEOUT).await,
|
||||
cli::Command::Zwift {
|
||||
device,
|
||||
duration,
|
||||
|
||||
Reference in New Issue
Block a user