1 ///! Rule group for tracking connection related issues.
2 use chrono::NaiveDateTime;
3 use std::collections::{HashMap, HashSet, VecDeque};
4 use std::convert::Into;
5 use std::io::Write;
6 use std::slice::Iter;
7
8 use crate::engine::{Rule, RuleGroup, Signal};
9 use crate::parser::{Packet, PacketChild};
10 use hcidoc_packets::hci::{
11 Acl, AclCommandChild, Address, AuthenticatedPayloadTimeoutExpired, CommandChild,
12 ConnectionManagementCommandChild, DisconnectReason, Enable, ErrorCode, EventChild,
13 InitiatorFilterPolicy, LeConnectionManagementCommandChild, LeMetaEventChild,
14 LeSecurityCommandChild, NumberOfCompletedPackets, OpCode, ScoConnectionCommandChild,
15 SecurityCommandChild,
16 };
17
18 enum ConnectionSignal {
19 LinkKeyMismatch, // Peer forgets the link key or it mismatches ours. (b/284802375)
20 LongTermKeyMismatch, // Like LinkKeyMismatch but for LE cases. (b/303600602)
21 NocpDisconnect, // Peer is disconnected when NOCP packet isn't yet received. (b/249295604)
22 NocpTimeout, // Host doesn't receive NOCP packet 5 seconds after ACL is sent. (b/249295604)
23 ApteDisconnect, // Host doesn't receive a packet with valid MIC for a while. (b/299850738)
24 RemoteFeatureNoReply, // Host doesn't receive a response for a remote feature request. (b/300851411)
25 RemoteFeatureError, // Controller replies error for remote feature request. (b/292116133)
26 SecurityMode3, // Peer uses the unsupported legacy security mode 3. (b/260625799)
27 }
28
29 impl Into<&'static str> for ConnectionSignal {
into(self) -> &'static str30 fn into(self) -> &'static str {
31 match self {
32 ConnectionSignal::LinkKeyMismatch => "LinkKeyMismatch",
33 ConnectionSignal::LongTermKeyMismatch => "LongTermKeyMismatch",
34 ConnectionSignal::NocpDisconnect => "Nocp",
35 ConnectionSignal::NocpTimeout => "Nocp",
36 ConnectionSignal::ApteDisconnect => "AuthenticatedPayloadTimeoutExpired",
37 ConnectionSignal::RemoteFeatureError => "RemoteFeatureError",
38 ConnectionSignal::RemoteFeatureNoReply => "RemoteFeatureNoReply",
39 ConnectionSignal::SecurityMode3 => "UnsupportedSecurityMode3",
40 }
41 }
42 }
43
44 /// Valid values are in the range 0x0000-0x0EFF.
45 pub type ConnectionHandle = u16;
46
47 /// When we attempt to create a sco connection on an unknown handle, use this address as
48 /// a placeholder.
49 pub const UNKNOWN_SCO_ADDRESS: [u8; 6] = [0xdeu8, 0xad, 0xbe, 0xef, 0x00, 0x00];
50
51 /// The tolerance duration of not receiving an expected reply. If 5s elapsed and timeout occurs,
52 /// we blame the pending event for causing timeout. This is used to detect NOCP and others.
53 pub const TIMEOUT_TOLERANCE_TIME_MS: i64 = 5000;
54
55 pub(crate) struct NocpData {
56 /// Number of in-flight packets without a corresponding NOCP.
57 pub inflight_acl_ts: VecDeque<NaiveDateTime>,
58 }
59
60 impl NocpData {
new() -> Self61 fn new() -> Self {
62 Self { inflight_acl_ts: VecDeque::new() }
63 }
64 }
65
66 #[derive(Debug, Eq, PartialEq, Hash)]
67 enum PendingRemoteFeature {
68 Supported,
69 Extended,
70 Le,
71 }
72
73 impl PendingRemoteFeature {
iterate_all() -> Iter<'static, PendingRemoteFeature>74 fn iterate_all() -> Iter<'static, PendingRemoteFeature> {
75 static FEATS: [PendingRemoteFeature; 3] = [
76 PendingRemoteFeature::Supported,
77 PendingRemoteFeature::Extended,
78 PendingRemoteFeature::Le,
79 ];
80 FEATS.iter()
81 }
82 }
83
84 /// Keeps track of connections and identifies odd disconnections.
85 struct OddDisconnectionsRule {
86 /// Handles that had successful complete connections. The value has the timestamp of the
87 /// connection completion and the address of the device.
88 active_handles: HashMap<ConnectionHandle, (NaiveDateTime, Address)>,
89
90 connection_attempt: HashMap<Address, Packet>,
91 last_connection_attempt: Option<Address>,
92
93 le_connection_attempt: HashMap<Address, Packet>,
94 last_le_connection_attempt: Option<Address>,
95 last_le_connection_filter_policy: Option<InitiatorFilterPolicy>,
96
97 sco_connection_attempt: HashMap<Address, Packet>,
98 last_sco_connection_attempt: Option<Address>,
99
100 accept_list: HashSet<Address>,
101
102 /// Keep track of some number of |Number of Completed Packets| and filter to
103 /// identify bursts.
104 nocp_by_handle: HashMap<ConnectionHandle, NocpData>,
105
106 /// Number of |Authenticated Payload Timeout Expired| events hapened.
107 apte_by_handle: HashMap<ConnectionHandle, u32>,
108
109 /// Pending handles for read remote features.
110 pending_supported_feat: HashMap<ConnectionHandle, NaiveDateTime>,
111 pending_extended_feat: HashMap<ConnectionHandle, NaiveDateTime>,
112 pending_le_feat: HashMap<ConnectionHandle, NaiveDateTime>,
113 last_feat_handle: HashMap<PendingRemoteFeature, ConnectionHandle>,
114
115 /// When powering off, the controller might or might not reply disconnection request. Therefore
116 /// make this a special case.
117 pending_disconnect_due_to_host_power_off: HashSet<ConnectionHandle>,
118
119 /// Pre-defined signals discovered in the logs.
120 signals: Vec<Signal>,
121
122 /// Interesting occurrences surfaced by this rule.
123 reportable: Vec<(NaiveDateTime, String)>,
124 }
125
126 impl OddDisconnectionsRule {
new() -> Self127 pub fn new() -> Self {
128 OddDisconnectionsRule {
129 active_handles: HashMap::new(),
130 connection_attempt: HashMap::new(),
131 last_connection_attempt: None,
132 le_connection_attempt: HashMap::new(),
133 last_le_connection_attempt: None,
134 last_le_connection_filter_policy: None,
135 sco_connection_attempt: HashMap::new(),
136 last_sco_connection_attempt: None,
137 accept_list: HashSet::new(),
138 nocp_by_handle: HashMap::new(),
139 apte_by_handle: HashMap::new(),
140 pending_supported_feat: HashMap::new(),
141 pending_extended_feat: HashMap::new(),
142 pending_le_feat: HashMap::new(),
143 last_feat_handle: HashMap::new(),
144 pending_disconnect_due_to_host_power_off: HashSet::new(),
145 signals: vec![],
146 reportable: vec![],
147 }
148 }
149
process_classic_connection(&mut self, address: Address, packet: &Packet)150 fn process_classic_connection(&mut self, address: Address, packet: &Packet) {
151 self.last_connection_attempt = Some(address);
152 if let Some(p) = self.connection_attempt.insert(address, packet.clone()) {
153 self.reportable.push((
154 p.ts,
155 format!("Dangling connection attempt at {:?} replaced with {:?}", p, packet),
156 ));
157 }
158 }
159
convert_sco_handle_to_address(&self, handle: ConnectionHandle) -> Address160 fn convert_sco_handle_to_address(&self, handle: ConnectionHandle) -> Address {
161 match self.active_handles.get(&handle).as_ref() {
162 Some((_ts, address)) => address.clone(),
163 None => Address::from(&UNKNOWN_SCO_ADDRESS),
164 }
165 }
166
process_sync_connection(&mut self, address: Address, packet: &Packet)167 fn process_sync_connection(&mut self, address: Address, packet: &Packet) {
168 self.last_sco_connection_attempt = Some(address);
169 if let Some(p) = self.sco_connection_attempt.insert(address, packet.clone()) {
170 self.reportable.push((
171 p.ts,
172 format!("Dangling sco connection attempt at {:?} replaced with {:?}", p, packet),
173 ));
174 }
175 }
176
process_le_create_connection( &mut self, address: Address, policy: InitiatorFilterPolicy, packet: &Packet, )177 fn process_le_create_connection(
178 &mut self,
179 address: Address,
180 policy: InitiatorFilterPolicy,
181 packet: &Packet,
182 ) {
183 self.last_le_connection_attempt = Some(address);
184 self.last_le_connection_filter_policy = Some(policy);
185 if let Some(p) = self.le_connection_attempt.insert(address, packet.clone()) {
186 self.reportable.push((
187 p.ts,
188 format!("Dangling LE connection attempt at {:?} replaced with {:?}", p, packet),
189 ));
190 }
191 }
192
process_add_accept_list(&mut self, address: Address, _packet: &Packet)193 fn process_add_accept_list(&mut self, address: Address, _packet: &Packet) {
194 self.accept_list.insert(address);
195 }
196
process_remove_accept_list(&mut self, address: Address, _packet: &Packet)197 fn process_remove_accept_list(&mut self, address: Address, _packet: &Packet) {
198 self.accept_list.remove(&address);
199 }
200
process_clear_accept_list(&mut self, _packet: &Packet)201 fn process_clear_accept_list(&mut self, _packet: &Packet) {
202 self.accept_list.clear();
203 }
204
get_feature_pending_map( &mut self, pending_type: &PendingRemoteFeature, ) -> &mut HashMap<ConnectionHandle, NaiveDateTime>205 fn get_feature_pending_map(
206 &mut self,
207 pending_type: &PendingRemoteFeature,
208 ) -> &mut HashMap<ConnectionHandle, NaiveDateTime> {
209 match pending_type {
210 PendingRemoteFeature::Supported => &mut self.pending_supported_feat,
211 PendingRemoteFeature::Extended => &mut self.pending_extended_feat,
212 PendingRemoteFeature::Le => &mut self.pending_le_feat,
213 }
214 }
215
process_remote_feat_cmd( &mut self, feat_type: PendingRemoteFeature, handle: &ConnectionHandle, packet: &Packet, )216 fn process_remote_feat_cmd(
217 &mut self,
218 feat_type: PendingRemoteFeature,
219 handle: &ConnectionHandle,
220 packet: &Packet,
221 ) {
222 self.get_feature_pending_map(&feat_type).insert(*handle, packet.ts);
223 self.last_feat_handle.insert(feat_type, *handle);
224 }
225
process_disconnect_cmd( &mut self, reason: DisconnectReason, handle: ConnectionHandle, packet: &Packet, )226 fn process_disconnect_cmd(
227 &mut self,
228 reason: DisconnectReason,
229 handle: ConnectionHandle,
230 packet: &Packet,
231 ) {
232 // If reason is power off, the host might not wait for connection complete event
233 if reason == DisconnectReason::RemoteDeviceTerminatedConnectionPowerOff {
234 self.process_disconn_complete_ev(handle, packet);
235 self.pending_disconnect_due_to_host_power_off.insert(handle);
236 }
237 }
238
process_command_status(&mut self, status: ErrorCode, opcode: OpCode, packet: &Packet)239 fn process_command_status(&mut self, status: ErrorCode, opcode: OpCode, packet: &Packet) {
240 match opcode {
241 OpCode::CreateConnection
242 | OpCode::AcceptConnectionRequest
243 | OpCode::SetupSynchronousConnection
244 | OpCode::AcceptSynchronousConnection
245 | OpCode::EnhancedSetupSynchronousConnection
246 | OpCode::EnhancedAcceptSynchronousConnection
247 | OpCode::LeCreateConnection
248 | OpCode::LeExtendedCreateConnection => {
249 self.process_command_status_conn(status, opcode, packet);
250 }
251
252 OpCode::ReadRemoteSupportedFeatures
253 | OpCode::ReadRemoteExtendedFeatures
254 | OpCode::LeReadRemoteFeatures => {
255 self.process_command_status_feat(status, opcode, packet);
256 }
257
258 _ => {}
259 }
260 }
261
process_command_status_conn(&mut self, status: ErrorCode, opcode: OpCode, packet: &Packet)262 fn process_command_status_conn(&mut self, status: ErrorCode, opcode: OpCode, packet: &Packet) {
263 // Clear last connection attempt since it was successful.
264 let last_address = match opcode {
265 OpCode::CreateConnection | OpCode::AcceptConnectionRequest => {
266 self.last_connection_attempt.take()
267 }
268
269 OpCode::SetupSynchronousConnection
270 | OpCode::AcceptSynchronousConnection
271 | OpCode::EnhancedSetupSynchronousConnection
272 | OpCode::EnhancedAcceptSynchronousConnection => {
273 self.last_sco_connection_attempt.take()
274 }
275
276 OpCode::LeCreateConnection | OpCode::LeExtendedCreateConnection => {
277 self.last_le_connection_attempt.take()
278 }
279
280 _ => return,
281 };
282
283 if let Some(address) = last_address {
284 if status != ErrorCode::Success {
285 self.reportable.push((
286 packet.ts,
287 format!("Failing command status on [{}]: {:?}", address, opcode),
288 ));
289
290 // Also remove the connection attempt.
291 match opcode {
292 OpCode::CreateConnection | OpCode::AcceptConnectionRequest => {
293 self.connection_attempt.remove(&address);
294 }
295
296 OpCode::SetupSynchronousConnection
297 | OpCode::AcceptSynchronousConnection
298 | OpCode::EnhancedSetupSynchronousConnection
299 | OpCode::EnhancedAcceptSynchronousConnection => {
300 self.sco_connection_attempt.remove(&address);
301 }
302
303 OpCode::LeCreateConnection | OpCode::LeExtendedCreateConnection => {
304 self.le_connection_attempt.remove(&address);
305 self.last_le_connection_filter_policy = None;
306 }
307
308 _ => (),
309 }
310 }
311 } else {
312 if status != ErrorCode::Success {
313 self.reportable.push((
314 packet.ts,
315 format!("Failing command status on unknown address: {:?}", opcode),
316 ));
317 }
318 }
319 }
320
process_command_status_feat(&mut self, status: ErrorCode, opcode: OpCode, packet: &Packet)321 fn process_command_status_feat(&mut self, status: ErrorCode, opcode: OpCode, packet: &Packet) {
322 let feat_type = match opcode {
323 OpCode::ReadRemoteSupportedFeatures => PendingRemoteFeature::Supported,
324 OpCode::ReadRemoteExtendedFeatures => PendingRemoteFeature::Extended,
325 OpCode::LeReadRemoteFeatures => PendingRemoteFeature::Le,
326 _ => return,
327 };
328
329 // If handle is not known, probably the request comes before btsnoop starts. In any case,
330 // the command complete event will still complain. So let's just return here.
331 let handle = match self.last_feat_handle.remove(&feat_type) {
332 Some(handle) => handle,
333 None => return,
334 };
335
336 // If failed, there won't be a following command complete event. So treat this as the
337 // command complete.
338 if status != ErrorCode::Success {
339 self.process_remote_feat_ev(feat_type, status, handle, packet);
340 }
341 }
342
process_conn_complete_ev( &mut self, status: ErrorCode, handle: ConnectionHandle, address: Address, packet: &Packet, )343 fn process_conn_complete_ev(
344 &mut self,
345 status: ErrorCode,
346 handle: ConnectionHandle,
347 address: Address,
348 packet: &Packet,
349 ) {
350 if let Some(_) = self.connection_attempt.remove(&address) {
351 if status == ErrorCode::Success {
352 self.active_handles.insert(handle, (packet.ts, address));
353 self.pending_disconnect_due_to_host_power_off.remove(&handle);
354 } else {
355 self.reportable.push((
356 packet.ts,
357 format!(
358 "ConnectionComplete error {:?} for addr {} (handle={})",
359 status, address, handle
360 ),
361 ));
362 }
363 } else {
364 self.reportable.push((
365 packet.ts,
366 format!(
367 "ConnectionComplete with status {:?} for unknown addr {} (handle={})",
368 status, address, handle
369 ),
370 ));
371 }
372 }
373
process_disconn_complete_ev(&mut self, handle: ConnectionHandle, packet: &Packet)374 fn process_disconn_complete_ev(&mut self, handle: ConnectionHandle, packet: &Packet) {
375 // If previously host send disconnect with power off reason, disconnection has been handled.
376 if self.pending_disconnect_due_to_host_power_off.remove(&handle) {
377 return;
378 }
379
380 self.active_handles.remove(&handle);
381
382 // Check if this is a NOCP type disconnection and flag it.
383 if let Some(nocp_data) = self.nocp_by_handle.get_mut(&handle) {
384 if let Some(acl_front_ts) = nocp_data.inflight_acl_ts.pop_front() {
385 let duration_since_acl = packet.ts.signed_duration_since(acl_front_ts);
386 if duration_since_acl.num_milliseconds() > TIMEOUT_TOLERANCE_TIME_MS {
387 self.signals.push(Signal {
388 index: packet.index,
389 ts: packet.ts,
390 tag: ConnectionSignal::NocpDisconnect.into(),
391 });
392
393 self.reportable.push((
394 packet.ts,
395 format!("DisconnectionComplete for handle({}) showed incomplete in-flight ACL at {}",
396 handle, acl_front_ts)));
397 }
398 }
399 }
400 // Remove nocp information for handles that were removed.
401 self.nocp_by_handle.remove(&handle);
402
403 // Check if auth payload timeout happened.
404 if let Some(apte_count) = self.apte_by_handle.remove(&handle) {
405 self.signals.push(Signal {
406 index: packet.index,
407 ts: packet.ts,
408 tag: ConnectionSignal::ApteDisconnect.into(),
409 });
410
411 self.reportable.push((
412 packet.ts,
413 format!("DisconnectionComplete with {} Authenticated Payload Timeout Expired (handle={})",
414 apte_count, handle))
415 );
416 }
417
418 // Check if remote feature request is pending
419 for feat_type in PendingRemoteFeature::iterate_all() {
420 if let Some(ts) = self.get_feature_pending_map(feat_type).remove(&handle) {
421 let elapsed_time_ms = packet.ts.signed_duration_since(ts).num_milliseconds();
422 if elapsed_time_ms > TIMEOUT_TOLERANCE_TIME_MS {
423 self.signals.push(Signal {
424 index: packet.index,
425 ts: packet.ts,
426 tag: ConnectionSignal::RemoteFeatureNoReply.into(),
427 });
428
429 self.reportable.push((
430 packet.ts,
431 format!(
432 "Handle {} doesn't respond to {:?} feature request at {}.",
433 handle,
434 feat_type,
435 ts.time()
436 ),
437 ));
438 }
439 }
440 }
441 }
442
process_sync_conn_complete_ev( &mut self, status: ErrorCode, handle: ConnectionHandle, address: Address, packet: &Packet, )443 fn process_sync_conn_complete_ev(
444 &mut self,
445 status: ErrorCode,
446 handle: ConnectionHandle,
447 address: Address,
448 packet: &Packet,
449 ) {
450 if let Some(_) = self.sco_connection_attempt.remove(&address) {
451 if status == ErrorCode::Success {
452 self.active_handles.insert(handle, (packet.ts, address));
453 self.pending_disconnect_due_to_host_power_off.remove(&handle);
454 } else {
455 self.reportable.push((
456 packet.ts,
457 format!(
458 "SynchronousConnectionComplete error {:?} for addr {} (handle={})",
459 status, address, handle
460 ),
461 ));
462 }
463 } else {
464 self.reportable.push((
465 packet.ts,
466 format!(
467 "SynchronousConnectionComplete with status {:?} for unknown addr {} (handle={})",
468 status,
469 address,
470 handle
471 ),
472 ));
473 }
474 }
475
process_le_conn_complete_ev( &mut self, status: ErrorCode, handle: ConnectionHandle, address: Address, packet: &Packet, )476 fn process_le_conn_complete_ev(
477 &mut self,
478 status: ErrorCode,
479 handle: ConnectionHandle,
480 address: Address,
481 packet: &Packet,
482 ) {
483 let use_accept_list = self
484 .last_le_connection_filter_policy
485 .map_or(false, |policy| policy == InitiatorFilterPolicy::UseFilterAcceptList);
486 let addr_to_remove =
487 if use_accept_list { hcidoc_packets::hci::EMPTY_ADDRESS } else { address };
488
489 if let Some(_) = self.le_connection_attempt.remove(&addr_to_remove) {
490 if status == ErrorCode::Success {
491 self.active_handles.insert(handle, (packet.ts, address));
492 self.pending_disconnect_due_to_host_power_off.remove(&handle);
493 } else {
494 let message = if use_accept_list {
495 format!("LeConnectionComplete error {:?} for accept list", status)
496 } else {
497 format!(
498 "LeConnectionComplete error {:?} for addr {} (handle={})",
499 status, address, handle
500 )
501 };
502 self.reportable.push((packet.ts, message));
503 }
504 } else {
505 self.reportable.push((
506 packet.ts,
507 format!(
508 "LeConnectionComplete with status {:?} for unknown addr {} (handle={})",
509 status, address, handle
510 ),
511 ));
512 }
513 }
514
process_acl_tx(&mut self, acl_tx: &Acl, packet: &Packet)515 fn process_acl_tx(&mut self, acl_tx: &Acl, packet: &Packet) {
516 let handle = acl_tx.get_handle();
517
518 // Insert empty Nocp data for handle if it doesn't exist.
519 if !self.nocp_by_handle.contains_key(&handle) {
520 self.nocp_by_handle.insert(handle, NocpData::new());
521 }
522
523 if let Some(nocp_data) = self.nocp_by_handle.get_mut(&handle) {
524 nocp_data.inflight_acl_ts.push_back(packet.ts);
525 }
526 }
527
process_nocp(&mut self, nocp: &NumberOfCompletedPackets, packet: &Packet)528 fn process_nocp(&mut self, nocp: &NumberOfCompletedPackets, packet: &Packet) {
529 let ts = &packet.ts;
530 for completed_packet in nocp.get_completed_packets() {
531 let handle = completed_packet.connection_handle;
532 let num = completed_packet.host_num_of_completed_packets;
533 if !self.nocp_by_handle.contains_key(&handle) {
534 self.nocp_by_handle.insert(handle, NocpData::new());
535 }
536
537 if let Some(nocp_data) = self.nocp_by_handle.get_mut(&handle) {
538 for _i in 0..num {
539 if let Some(acl_front_ts) = nocp_data.inflight_acl_ts.pop_front() {
540 let duration_since_acl = ts.signed_duration_since(acl_front_ts);
541 if duration_since_acl.num_milliseconds() > TIMEOUT_TOLERANCE_TIME_MS {
542 self.signals.push(Signal {
543 index: packet.index,
544 ts: packet.ts,
545 tag: ConnectionSignal::NocpTimeout.into(),
546 });
547 self.reportable.push((
548 packet.ts,
549 format!(
550 "Nocp sent {} ms after ACL on handle({}).",
551 duration_since_acl.num_milliseconds(),
552 handle
553 ),
554 ));
555 }
556 }
557 }
558 }
559 }
560 }
561
process_apte(&mut self, apte: &AuthenticatedPayloadTimeoutExpired, _packet: &Packet)562 fn process_apte(&mut self, apte: &AuthenticatedPayloadTimeoutExpired, _packet: &Packet) {
563 let handle = apte.get_connection_handle();
564 *self.apte_by_handle.entry(handle).or_insert(0) += 1;
565 }
566
process_remote_feat_ev( &mut self, feat_type: PendingRemoteFeature, status: ErrorCode, handle: ConnectionHandle, packet: &Packet, )567 fn process_remote_feat_ev(
568 &mut self,
569 feat_type: PendingRemoteFeature,
570 status: ErrorCode,
571 handle: ConnectionHandle,
572 packet: &Packet,
573 ) {
574 let feat_map = self.get_feature_pending_map(&feat_type);
575
576 if feat_map.remove(&handle) == None {
577 self.reportable.push((
578 packet.ts,
579 format!("Got remote {:?} for unknown handle {}", feat_type, handle),
580 ));
581 }
582
583 if status != ErrorCode::Success {
584 self.signals.push(Signal {
585 index: packet.index,
586 ts: packet.ts,
587 tag: ConnectionSignal::RemoteFeatureError.into(),
588 });
589
590 self.reportable.push((
591 packet.ts,
592 format!("Got {:?} for remote {:?} feature, handle {}", status, feat_type, handle),
593 ));
594 }
595 }
596
process_reset(&mut self)597 fn process_reset(&mut self) {
598 self.active_handles.clear();
599 self.connection_attempt.clear();
600 self.last_connection_attempt = None;
601 self.le_connection_attempt.clear();
602 self.last_le_connection_attempt = None;
603 self.last_le_connection_filter_policy = None;
604 self.sco_connection_attempt.clear();
605 self.last_sco_connection_attempt = None;
606 self.accept_list.clear();
607 self.nocp_by_handle.clear();
608 self.apte_by_handle.clear();
609 self.pending_supported_feat.clear();
610 self.pending_extended_feat.clear();
611 self.pending_le_feat.clear();
612 self.last_feat_handle.clear();
613 self.pending_disconnect_due_to_host_power_off.clear();
614 }
615
process_system_note(&mut self, note: &String)616 fn process_system_note(&mut self, note: &String) {
617 // Carryover section doesn't contain the NOCP from the controller.
618 // The note may contain zero bytes, so don't check for exact string.
619 if note.contains("END OF CARRYOVER SECTION") {
620 self.nocp_by_handle.clear();
621 }
622 }
623 }
624
625 impl Rule for OddDisconnectionsRule {
process(&mut self, packet: &Packet)626 fn process(&mut self, packet: &Packet) {
627 match &packet.inner {
628 PacketChild::HciCommand(cmd) => match cmd.specialize() {
629 CommandChild::AclCommand(aclpkt) => match aclpkt.specialize() {
630 AclCommandChild::ConnectionManagementCommand(conn) => match conn.specialize() {
631 ConnectionManagementCommandChild::CreateConnection(cc) => {
632 self.process_classic_connection(cc.get_bd_addr(), packet);
633 }
634 ConnectionManagementCommandChild::AcceptConnectionRequest(ac) => {
635 self.process_classic_connection(ac.get_bd_addr(), packet);
636 }
637 ConnectionManagementCommandChild::ReadRemoteSupportedFeatures(rrsf) => {
638 self.process_remote_feat_cmd(
639 PendingRemoteFeature::Supported,
640 &rrsf.get_connection_handle(),
641 packet,
642 );
643 }
644 ConnectionManagementCommandChild::ReadRemoteExtendedFeatures(rref) => {
645 self.process_remote_feat_cmd(
646 PendingRemoteFeature::Extended,
647 &rref.get_connection_handle(),
648 packet,
649 );
650 }
651 // End ConnectionManagementCommand.specialize()
652 _ => {}
653 },
654 AclCommandChild::ScoConnectionCommand(sco_con) => match sco_con.specialize() {
655 ScoConnectionCommandChild::SetupSynchronousConnection(ssc) => {
656 let address =
657 self.convert_sco_handle_to_address(ssc.get_connection_handle());
658 self.process_sync_connection(address, packet);
659 }
660 ScoConnectionCommandChild::EnhancedSetupSynchronousConnection(esc) => {
661 let address =
662 self.convert_sco_handle_to_address(esc.get_connection_handle());
663 self.process_sync_connection(address, packet);
664 }
665 ScoConnectionCommandChild::AcceptSynchronousConnection(asc) => {
666 self.process_sync_connection(asc.get_bd_addr(), packet);
667 }
668 ScoConnectionCommandChild::EnhancedAcceptSynchronousConnection(easc) => {
669 self.process_sync_connection(easc.get_bd_addr(), packet);
670 }
671 // End ScoConnectionCommand.specialize()
672 _ => {}
673 },
674 AclCommandChild::LeConnectionManagementCommand(le_conn) => match le_conn
675 .specialize()
676 {
677 LeConnectionManagementCommandChild::LeCreateConnection(lcc) => {
678 self.process_le_create_connection(
679 lcc.get_peer_address(),
680 lcc.get_initiator_filter_policy(),
681 packet,
682 );
683 }
684 LeConnectionManagementCommandChild::LeExtendedCreateConnection(lecc) => {
685 self.process_le_create_connection(
686 lecc.get_peer_address(),
687 lecc.get_initiator_filter_policy(),
688 packet,
689 );
690 }
691 LeConnectionManagementCommandChild::LeAddDeviceToFilterAcceptList(laac) => {
692 self.process_add_accept_list(laac.get_address(), packet);
693 }
694 LeConnectionManagementCommandChild::LeRemoveDeviceFromFilterAcceptList(
695 lrac,
696 ) => {
697 self.process_remove_accept_list(lrac.get_address(), packet);
698 }
699 LeConnectionManagementCommandChild::LeClearFilterAcceptList(_lcac) => {
700 self.process_clear_accept_list(packet);
701 }
702 LeConnectionManagementCommandChild::LeReadRemoteFeatures(lrrf) => {
703 self.process_remote_feat_cmd(
704 PendingRemoteFeature::Le,
705 &lrrf.get_connection_handle(),
706 packet,
707 );
708 }
709 // End LeConnectionManagementCommand.specialize()
710 _ => {}
711 },
712 AclCommandChild::Disconnect(dc_conn) => {
713 self.process_disconnect_cmd(
714 dc_conn.get_reason(),
715 dc_conn.get_connection_handle(),
716 packet,
717 );
718 }
719
720 // End AclCommand.specialize()
721 _ => (),
722 },
723 CommandChild::Reset(_) => {
724 self.process_reset();
725 }
726
727 // End HciCommand.specialize()
728 _ => (),
729 },
730
731 PacketChild::HciEvent(ev) => match ev.specialize() {
732 EventChild::CommandStatus(cs) => {
733 self.process_command_status(cs.get_status(), cs.get_command_op_code(), packet);
734 }
735 EventChild::ConnectionComplete(cc) => {
736 self.process_conn_complete_ev(
737 cc.get_status(),
738 cc.get_connection_handle(),
739 cc.get_bd_addr(),
740 packet,
741 );
742 }
743 EventChild::DisconnectionComplete(dsc) => {
744 self.process_disconn_complete_ev(dsc.get_connection_handle(), packet);
745 }
746 EventChild::SynchronousConnectionComplete(scc) => {
747 self.process_sync_conn_complete_ev(
748 scc.get_status(),
749 scc.get_connection_handle(),
750 scc.get_bd_addr(),
751 packet,
752 );
753 }
754 EventChild::NumberOfCompletedPackets(nocp) => {
755 self.process_nocp(&nocp, packet);
756 }
757 EventChild::AuthenticatedPayloadTimeoutExpired(apte) => {
758 self.process_apte(&apte, packet);
759 }
760 EventChild::ReadRemoteSupportedFeaturesComplete(rsfc) => {
761 self.process_remote_feat_ev(
762 PendingRemoteFeature::Supported,
763 rsfc.get_status(),
764 rsfc.get_connection_handle(),
765 packet,
766 );
767 }
768 EventChild::ReadRemoteExtendedFeaturesComplete(refc) => {
769 self.process_remote_feat_ev(
770 PendingRemoteFeature::Extended,
771 refc.get_status(),
772 refc.get_connection_handle(),
773 packet,
774 );
775 }
776 EventChild::LeMetaEvent(lme) => match lme.specialize() {
777 LeMetaEventChild::LeConnectionComplete(lcc) => {
778 self.process_le_conn_complete_ev(
779 lcc.get_status(),
780 lcc.get_connection_handle(),
781 lcc.get_peer_address(),
782 packet,
783 );
784 }
785 LeMetaEventChild::LeEnhancedConnectionComplete(lecc) => {
786 self.process_le_conn_complete_ev(
787 lecc.get_status(),
788 lecc.get_connection_handle(),
789 lecc.get_peer_address(),
790 packet,
791 );
792 }
793 LeMetaEventChild::LeReadRemoteFeaturesComplete(lrrfc) => {
794 self.process_remote_feat_ev(
795 PendingRemoteFeature::Le,
796 lrrfc.get_status(),
797 lrrfc.get_connection_handle(),
798 packet,
799 );
800 }
801 // End LeMetaEvent.specialize()
802 _ => {}
803 },
804
805 // End HciEvent.specialize()
806 _ => (),
807 },
808
809 // Use tx packets for nocp tracking.
810 PacketChild::AclTx(tx) => {
811 self.process_acl_tx(&tx, packet);
812 }
813
814 // We don't do anything with RX packets yet.
815 PacketChild::AclRx(_) => (),
816
817 PacketChild::SystemNote(note) => {
818 self.process_system_note(note);
819 }
820
821 // End packet.inner match
822 _ => (),
823 }
824 }
825
report(&self, writer: &mut dyn Write)826 fn report(&self, writer: &mut dyn Write) {
827 if self.reportable.len() > 0 {
828 let _ = writeln!(writer, "OddDisconnectionsRule report:");
829 for (ts, message) in self.reportable.iter() {
830 let _ = writeln!(writer, "[{:?}] {}", ts, message);
831 }
832 }
833 }
834
report_signals(&self) -> &[Signal]835 fn report_signals(&self) -> &[Signal] {
836 self.signals.as_slice()
837 }
838 }
839
840 // What state are we in for the LinkKeyMismatchRule state?
841 #[derive(Debug, PartialEq)]
842 enum LinkKeyMismatchState {
843 Requested, // Controller requested link key to the host
844 Replied, // Host replied the link key
845 }
846
847 /// Identifies instances when the peer forgets the link key or it mismatches with ours.
848 /// For classic connections, first the controller asks for the link key via Link Key Request, then
849 /// the host replies with Link Key Request Reply, finally the controller will report the result,
850 /// usually via AuthenticationComplete.
851 /// For LE connections, the host passes the Long Term Key (LTK) via LE Start Encryption, then the
852 /// controller reports the result via Encryption Change event. There are also LE Long Term Key
853 /// Requests from the controller, but that is only used when the device is a peripheral.
854 struct LinkKeyMismatchRule {
855 /// Addresses in authenticating process
856 states: HashMap<Address, LinkKeyMismatchState>,
857
858 /// Active handles
859 handles: HashMap<ConnectionHandle, Address>,
860
861 /// Handles pending for LE encryption
862 pending_le_encrypt: HashSet<ConnectionHandle>,
863
864 /// Pre-defined signals discovered in the logs.
865 signals: Vec<Signal>,
866
867 /// Interesting occurrences surfaced by this rule.
868 reportable: Vec<(NaiveDateTime, String)>,
869 }
870
871 impl LinkKeyMismatchRule {
new() -> Self872 pub fn new() -> Self {
873 LinkKeyMismatchRule {
874 states: HashMap::new(),
875 handles: HashMap::new(),
876 pending_le_encrypt: HashSet::new(),
877 signals: vec![],
878 reportable: vec![],
879 }
880 }
881
process_address_auth(&mut self, status: ErrorCode, address: Address, packet: &Packet)882 fn process_address_auth(&mut self, status: ErrorCode, address: Address, packet: &Packet) {
883 if status == ErrorCode::AuthenticationFailure {
884 if let Some(LinkKeyMismatchState::Replied) = self.states.get(&address) {
885 self.signals.push(Signal {
886 index: packet.index,
887 ts: packet.ts,
888 tag: ConnectionSignal::LinkKeyMismatch.into(),
889 });
890
891 self.reportable.push((
892 packet.ts,
893 format!("Peer {} forgets the link key, or it mismatches with ours.", address),
894 ));
895 }
896 }
897 self.states.remove(&address);
898 }
899
process_handle_auth( &mut self, status: ErrorCode, handle: ConnectionHandle, packet: &Packet, )900 fn process_handle_auth(
901 &mut self,
902 status: ErrorCode,
903 handle: ConnectionHandle,
904 packet: &Packet,
905 ) {
906 if let Some(address) = self.handles.get(&handle) {
907 self.process_address_auth(status, *address, packet);
908 }
909 }
910
process_request_link_key(&mut self, address: Address)911 fn process_request_link_key(&mut self, address: Address) {
912 self.states.insert(address, LinkKeyMismatchState::Requested);
913 }
914
process_reply_link_key(&mut self, address: Address, key_exist: bool)915 fn process_reply_link_key(&mut self, address: Address, key_exist: bool) {
916 if !key_exist {
917 self.states.remove(&address);
918 return;
919 }
920
921 if let Some(LinkKeyMismatchState::Requested) = self.states.get(&address) {
922 self.states.insert(address, LinkKeyMismatchState::Replied);
923 }
924 }
925
process_encryption_change( &mut self, status: ErrorCode, handle: ConnectionHandle, packet: &Packet, )926 fn process_encryption_change(
927 &mut self,
928 status: ErrorCode,
929 handle: ConnectionHandle,
930 packet: &Packet,
931 ) {
932 if status != ErrorCode::Success {
933 let address_format = self
934 .handles
935 .get(&handle)
936 .map_or(format!("handle {}", handle), |addr| format!("{}", addr));
937 self.reportable.push((
938 packet.ts,
939 format!("Encryption failure with {:?} for {}", status, address_format),
940 ));
941
942 if self.pending_le_encrypt.contains(&handle) {
943 self.signals.push(Signal {
944 index: packet.index,
945 ts: packet.ts,
946 tag: ConnectionSignal::LongTermKeyMismatch.into(),
947 });
948 }
949 }
950
951 self.pending_le_encrypt.remove(&handle);
952 }
953
process_reset(&mut self)954 fn process_reset(&mut self) {
955 self.states.clear();
956 self.handles.clear();
957 self.pending_le_encrypt.clear();
958 }
959 }
960
961 impl Rule for LinkKeyMismatchRule {
process(&mut self, packet: &Packet)962 fn process(&mut self, packet: &Packet) {
963 match &packet.inner {
964 PacketChild::HciEvent(ev) => match ev.specialize() {
965 EventChild::ConnectionComplete(ev) => {
966 if ev.get_status() == ErrorCode::Success {
967 self.handles.insert(ev.get_connection_handle(), ev.get_bd_addr());
968 }
969 }
970 EventChild::LinkKeyRequest(ev) => {
971 self.process_request_link_key(ev.get_bd_addr());
972 }
973 EventChild::SimplePairingComplete(ev) => {
974 self.process_address_auth(ev.get_status(), ev.get_bd_addr(), &packet);
975 }
976 EventChild::AuthenticationComplete(ev) => {
977 self.process_handle_auth(ev.get_status(), ev.get_connection_handle(), &packet);
978 }
979 EventChild::DisconnectionComplete(ev) => {
980 self.process_handle_auth(ev.get_status(), ev.get_connection_handle(), &packet);
981 self.handles.remove(&ev.get_connection_handle());
982 }
983 EventChild::EncryptionChange(ev) => {
984 self.process_encryption_change(
985 ev.get_status(),
986 ev.get_connection_handle(),
987 &packet,
988 );
989 }
990 EventChild::LeMetaEvent(ev) => match ev.specialize() {
991 LeMetaEventChild::LeConnectionComplete(ev) => {
992 if ev.get_status() == ErrorCode::Success {
993 self.handles.insert(ev.get_connection_handle(), ev.get_peer_address());
994 }
995 }
996 LeMetaEventChild::LeEnhancedConnectionComplete(ev) => {
997 if ev.get_status() == ErrorCode::Success {
998 self.handles.insert(ev.get_connection_handle(), ev.get_peer_address());
999 }
1000 }
1001
1002 // EventChild::LeMetaEvent(ev).specialize()
1003 _ => {}
1004 },
1005
1006 // PacketChild::HciEvent(ev).specialize()
1007 _ => {}
1008 },
1009
1010 PacketChild::HciCommand(cmd) => match cmd.specialize() {
1011 CommandChild::AclCommand(cmd) => match cmd.specialize() {
1012 // Have an arm for Disconnect since sometimes we don't receive disconnect
1013 // event when powering off. However, no need to actually match the reason
1014 // since we just clean the handle in both cases.
1015 AclCommandChild::Disconnect(cmd) => {
1016 self.process_handle_auth(
1017 ErrorCode::Success,
1018 cmd.get_connection_handle(),
1019 &packet,
1020 );
1021 self.handles.remove(&cmd.get_connection_handle());
1022 }
1023
1024 // CommandChild::AclCommand(cmd).specialize()
1025 _ => {}
1026 },
1027
1028 CommandChild::SecurityCommand(cmd) => match cmd.specialize() {
1029 SecurityCommandChild::LinkKeyRequestReply(cmd) => {
1030 self.process_reply_link_key(cmd.get_bd_addr(), true);
1031 }
1032 SecurityCommandChild::LinkKeyRequestNegativeReply(cmd) => {
1033 self.process_reply_link_key(cmd.get_bd_addr(), false);
1034 }
1035
1036 // CommandChild::SecurityCommand(cmd).specialize()
1037 _ => {}
1038 },
1039
1040 CommandChild::LeSecurityCommand(cmd) => match cmd.specialize() {
1041 LeSecurityCommandChild::LeStartEncryption(cmd) => {
1042 self.pending_le_encrypt.insert(cmd.get_connection_handle());
1043 }
1044
1045 // CommandChild::LeSecurityCommand(cmd).specialize()
1046 _ => {}
1047 },
1048
1049 CommandChild::Reset(_) => {
1050 self.process_reset();
1051 }
1052
1053 // PacketChild::HciCommand(cmd).specialize()
1054 _ => {}
1055 },
1056
1057 // packet.inner
1058 _ => {}
1059 }
1060 }
1061
report(&self, writer: &mut dyn Write)1062 fn report(&self, writer: &mut dyn Write) {
1063 if self.reportable.len() > 0 {
1064 let _ = writeln!(writer, "LinkKeyMismatchRule report:");
1065 for (ts, message) in self.reportable.iter() {
1066 let _ = writeln!(writer, "[{:?}] {}", ts, message);
1067 }
1068 }
1069 }
1070
report_signals(&self) -> &[Signal]1071 fn report_signals(&self) -> &[Signal] {
1072 self.signals.as_slice()
1073 }
1074 }
1075
1076 struct SecurityMode3Rule {
1077 /// Pre-defined signals discovered in the logs.
1078 signals: Vec<Signal>,
1079
1080 /// Interesting occurrences surfaced by this rule.
1081 reportable: Vec<(NaiveDateTime, String)>,
1082 }
1083
1084 impl SecurityMode3Rule {
new() -> Self1085 pub fn new() -> Self {
1086 SecurityMode3Rule { signals: vec![], reportable: vec![] }
1087 }
1088
process_connect_complete( &mut self, status: ErrorCode, address: Address, encryption_enabled: Enable, packet: &Packet, )1089 fn process_connect_complete(
1090 &mut self,
1091 status: ErrorCode,
1092 address: Address,
1093 encryption_enabled: Enable,
1094 packet: &Packet,
1095 ) {
1096 // See figure 5.2 and 5.3 in BT spec v5.4 Vol 3 Part C 5.2 for security mode 3 explanation.
1097 // It is indicated by encryption before the link setup is complete.
1098 // Therefore we just need to observe the encryption_enabled parameter in conn complete evt.
1099 if status == ErrorCode::Success && encryption_enabled == Enable::Enabled {
1100 self.signals.push(Signal {
1101 index: packet.index,
1102 ts: packet.ts,
1103 tag: ConnectionSignal::SecurityMode3.into(),
1104 });
1105
1106 self.reportable.push((
1107 packet.ts,
1108 format!("Device {} uses unsupported legacy security mode 3 (b/260625799)", address),
1109 ));
1110 }
1111 }
1112 }
1113
1114 impl Rule for SecurityMode3Rule {
process(&mut self, packet: &Packet)1115 fn process(&mut self, packet: &Packet) {
1116 match &packet.inner {
1117 PacketChild::HciEvent(ev) => match ev.specialize() {
1118 EventChild::ConnectionComplete(ev) => {
1119 self.process_connect_complete(
1120 ev.get_status(),
1121 ev.get_bd_addr(),
1122 ev.get_encryption_enabled(),
1123 packet,
1124 );
1125 }
1126 _ => {}
1127 },
1128 _ => {}
1129 }
1130 }
1131
report(&self, writer: &mut dyn Write)1132 fn report(&self, writer: &mut dyn Write) {
1133 if self.reportable.len() > 0 {
1134 let _ = writeln!(writer, "SecurityMode3Rule report:");
1135 for (ts, message) in self.reportable.iter() {
1136 let _ = writeln!(writer, "[{:?}] {}", ts, message);
1137 }
1138 }
1139 }
1140
report_signals(&self) -> &[Signal]1141 fn report_signals(&self) -> &[Signal] {
1142 self.signals.as_slice()
1143 }
1144 }
1145
1146 /// Get a rule group with connection rules.
get_connections_group() -> RuleGroup1147 pub fn get_connections_group() -> RuleGroup {
1148 let mut group = RuleGroup::new();
1149 group.add_rule(Box::new(LinkKeyMismatchRule::new()));
1150 group.add_rule(Box::new(OddDisconnectionsRule::new()));
1151 group.add_rule(Box::new(SecurityMode3Rule::new()));
1152
1153 group
1154 }
1155