floss: Add nocp detection (2fc0fea6) · Commits · e / os / android_packages_modules_Bluetooth

floss/hcidoc/src/groups/connections.rs

+106 −13

Original line number	Diff line number	Diff line
		///! Rule group for tracking connection related issues.
		use chrono::NaiveDateTime;
		use std::collections::HashMap;
		use std::collections::{HashMap, VecDeque};
		use std::io::Write;

		use crate::engine::{Rule, RuleGroup};
		use crate::parser::{Packet, PacketChild};
		use bt_packets::custom_types::Address;
		use bt_packets::hci::{
		AclCommandChild, CommandChild, CommandStatusPacket, ConnectionManagementCommandChild,
		ErrorCode, EventChild, EventPacket, LeConnectionManagementCommandChild, LeMetaEventChild,
		OpCode, ScoConnectionCommandChild, SubeventCode,
		AclCommandChild, AclPacket, CommandChild, CommandStatusPacket,
		ConnectionManagementCommandChild, ErrorCode, EventChild, EventPacket,
		LeConnectionManagementCommandChild, LeMetaEventChild, NumberOfCompletedPacketsPacket, OpCode,
		ScoConnectionCommandChild, SubeventCode,
		};

		/// Valid values are in the range 0x0000-0x0EFF.
		@@ -22,6 +23,21 @@ pub const INVALID_CONN_HANDLE: u16 = 0xfffeu16;
		/// a placeholder.
		pub const UNKNOWN_SCO_ADDRESS: Address = Address { bytes: [0xde, 0xad, 0xbe, 0xef, 0x00, 0x00] };

		/// Any outstanding NOCP or disconnection that is more than 5s away from the sent ACL packet should
		/// result in an NOCP signal being generated.
		pub const NOCP_CORRELATION_TIME_MS: i64 = 5000;

		pub(crate) struct NocpData {
		/// Number of in-flight packets without a corresponding NOCP.
		pub inflight_acl_ts: VecDeque<NaiveDateTime>,
		}

		impl NocpData {
		fn new() -> Self {
		Self { inflight_acl_ts: VecDeque::new() }
		}
		}

		/// Keeps track of connections and identifies odd disconnections.
		struct OddDisconnectionsRule {
		/// Timestamp on first packet in current log.
		@@ -40,6 +56,10 @@ struct OddDisconnectionsRule {
		sco_connection_attempt: HashMap<Address, Packet>,
		last_sco_connection_attempt: Option<Address>,

		/// Keep track of some number of \|Number of Completed Packets\| and filter to
		/// identify bursts.
		nocp_by_handle: HashMap<ConnectionHandle, NocpData>,

		/// Interesting occurrences surfaced by this rule.
		reportable: Vec<(NaiveDateTime, String)>,
		}
		@@ -55,6 +75,7 @@ impl OddDisconnectionsRule {
		last_le_connection_attempt: None,
		sco_connection_attempt: HashMap::new(),
		last_sco_connection_attempt: None,
		nocp_by_handle: HashMap::new(),
		reportable: vec![],
		}
		}
		@@ -257,7 +278,24 @@ impl OddDisconnectionsRule {
		}

		EventChild::DisconnectionComplete(dsc) => {
		if self.active_handles.remove(&dsc.get_connection_handle()).is_none() {
		let handle = dsc.get_connection_handle();
		match self.active_handles.remove(&handle) {
		Some(_) => {
		// Check if this is a NOCP type disconnection and flag it.
		match self.nocp_by_handle.get_mut(&handle) {
		Some(nocp_data) => {
		if let Some(acl_front_ts) = nocp_data.inflight_acl_ts.pop_front() {
		self.reportable.push((
		packet.ts,
		format!("DisconnectionComplete for handle({}) showed incomplete in-flight ACL at {}",
		handle, acl_front_ts)));
		}
		}
		None => (),
		}
		}

		None => {
		self.reportable.push((
		packet.ts,
		format!(
		@@ -269,6 +307,10 @@ impl OddDisconnectionsRule {
		}
		}

		// Remove nocp information for handles that were removed.
		self.nocp_by_handle.remove(&handle);
		}

		EventChild::SynchronousConnectionComplete(scc) => {
		match self.sco_connection_attempt.remove(&scc.get_bd_addr()) {
		Some(_) => {
		@@ -343,6 +385,45 @@ impl OddDisconnectionsRule {
		_ => (),
		}
		}

		pub fn process_acl_tx(&mut self, acl_tx: &AclPacket, packet: &Packet) {
		let handle = acl_tx.get_handle();

		// Insert empty Nocp data for handle if it doesn't exist.
		if !self.nocp_by_handle.contains_key(&handle) {
		self.nocp_by_handle.insert(handle, NocpData::new());
		}

		if let Some(nocp_data) = self.nocp_by_handle.get_mut(&handle) {
		nocp_data.inflight_acl_ts.push_back(packet.ts.clone());
		}
		}

		pub fn process_nocp(&mut self, nocp: &NumberOfCompletedPacketsPacket, packet: &Packet) {
		let ts = &packet.ts;
		for completed_packet in nocp.get_completed_packets() {
		let handle = completed_packet.connection_handle;
		if !self.nocp_by_handle.contains_key(&handle) {
		self.nocp_by_handle.insert(handle, NocpData::new());
		}

		if let Some(nocp_data) = self.nocp_by_handle.get_mut(&handle) {
		if let Some(acl_front_ts) = nocp_data.inflight_acl_ts.pop_front() {
		let duration_since_acl = ts.signed_duration_since(acl_front_ts);
		if duration_since_acl.num_milliseconds() > NOCP_CORRELATION_TIME_MS {
		self.reportable.push((
		packet.ts,
		format!(
		"Nocp sent {} ms after ACL on handle({}).",
		duration_since_acl.num_milliseconds(),
		handle
		),
		));
		}
		}
		}
		}
		}
		}

		impl Rule for OddDisconnectionsRule {
		@@ -396,8 +477,20 @@ impl Rule for OddDisconnectionsRule {
		_ => (),
		},

		EventChild::NumberOfCompletedPackets(nocp) => {
		self.process_nocp(&nocp, packet);
		}

		_ => (),
		},

		// Use tx packets for nocp tracking.
		PacketChild::AclTx(tx) => {
		self.process_acl_tx(&tx, packet);
		}

		// We don't do anything with RX packets yet.
		PacketChild::AclRx(_) => (),
		}
		}

floss/hcidoc/src/parser.rs

+13 −1

Original line number	Diff line number	Diff line
		@@ -5,7 +5,7 @@ use std::convert::TryFrom;
		use std::fs::File;
		use std::io::{Error, ErrorKind, Read, Seek};

		use bt_packets::hci::{CommandPacket, EventPacket};
		use bt_packets::hci::{AclPacket, CommandPacket, EventPacket};

		/// Linux snoop file header format. This format is used by `btmon` on Linux systems that have bluez
		/// installed.
		@@ -283,6 +283,8 @@ impl<'a> LogParser {
		pub enum PacketChild {
		HciCommand(CommandPacket),
		HciEvent(EventPacket),
		AclTx(AclPacket),
		AclRx(AclPacket),
		}

		impl<'a> TryFrom<&'a LinuxSnoopPacket> for PacketChild {
		@@ -300,6 +302,16 @@ impl<'a> TryFrom<&'a LinuxSnoopPacket> for PacketChild {
		Err(e) => Err(format!("Couldn't parse event: {:?}", e)),
		},

		LinuxSnoopOpcodes::AclTxPacket => match AclPacket::parse(item.data.as_slice()) {
		Ok(data) => Ok(PacketChild::AclTx(data)),
		Err(e) => Err(format!("Couldn't parse acl tx: {:?}", e)),
		},

		LinuxSnoopOpcodes::AclRxPacket => match AclPacket::parse(item.data.as_slice()) {
		Ok(data) => Ok(PacketChild::AclRx(data)),
		Err(e) => Err(format!("Couldn't parse acl rx: {:?}", e)),
		},

		// TODO(b/262928525) - Add packet handlers for more packet types.
		_ => Err(format!("Unhandled packet opcode: {:?}", item.opcode())),
		}