1 //! BT snoop logger
2
3 use crate::hal::internal::RawHal;
4 use bt_common::sys_prop;
5 use bt_packets::hci::{AclPacket, CommandPacket, EventPacket, IsoPacket, Packet, ScoPacket};
6 use bytes::{BufMut, Bytes, BytesMut};
7 use gddi::{module, part_out, provides, Stoppable};
8 use log::error;
9 use std::convert::TryFrom;
10 use std::sync::Arc;
11 use std::time::SystemTime;
12 use tokio::fs::{remove_file, rename, File};
13 use tokio::io::AsyncWriteExt;
14 use tokio::runtime::Runtime;
15 use tokio::select;
16 use tokio::sync::mpsc::{channel, Receiver, Sender, UnboundedReceiver};
17 use tokio::sync::Mutex;
18
19 #[part_out]
20 #[derive(Clone, Stoppable)]
21 struct Hal {
22 control: ControlHal,
23 acl: AclHal,
24 sco: ScoHal,
25 iso: IsoHal,
26 }
27
28 /// Command & event tx/rx
29 #[derive(Clone, Stoppable)]
30 pub struct ControlHal {
31 /// Transmit end
32 pub tx: Sender<CommandPacket>,
33 /// Receive end
34 pub rx: Arc<Mutex<Receiver<EventPacket>>>,
35 }
36
37 /// Acl tx/rx
38 #[derive(Clone, Stoppable)]
39 pub struct AclHal {
40 /// Transmit end
41 pub tx: Sender<AclPacket>,
42 /// Receive end
43 pub rx: Arc<Mutex<Receiver<AclPacket>>>,
44 }
45
46 /// Sco tx/rx
47 #[derive(Clone, Stoppable)]
48 pub struct ScoHal {
49 /// Transmit end
50 pub tx: Sender<ScoPacket>,
51 /// Receive end
52 pub rx: Arc<Mutex<Receiver<ScoPacket>>>,
53 }
54
55 /// Iso tx/rx
56 #[derive(Clone, Stoppable)]
57 pub struct IsoHal {
58 /// Transmit end
59 pub tx: Sender<IsoPacket>,
60 /// Receive end
61 pub rx: Arc<Mutex<Receiver<IsoPacket>>>,
62 }
63
64 /// The different modes snoop logging can be in
65 #[derive(Clone)]
66 pub enum SnoopMode {
67 /// All logs disabled
68 Disabled,
69 /// Only sanitized logs
70 Filtered,
71 /// Log everything
72 Full,
73 }
74
75 /// There was an error parsing the mode from a string
76 pub struct SnoopModeParseError;
77
78 impl std::str::FromStr for SnoopMode {
79 type Err = SnoopModeParseError;
80
from_str(s: &str) -> Result<Self, Self::Err>81 fn from_str(s: &str) -> Result<Self, Self::Err> {
82 match s {
83 "disabled" => Ok(SnoopMode::Disabled),
84 "filtered" => Ok(SnoopMode::Filtered),
85 "full" => Ok(SnoopMode::Full),
86 _ => Err(SnoopModeParseError),
87 }
88 }
89 }
90
91 /// All snoop logging config
92 #[derive(Clone, Stoppable)]
93 pub struct SnoopConfig {
94 path: String,
95 max_packets_per_file: u32,
96 mode: SnoopMode,
97 }
98
99 impl SnoopConfig {
100 /// Constructs a new snoop config
new() -> Self101 pub fn new() -> Self {
102 Self {
103 path: "/data/misc/bluetooth/logs/btsnoop_hci.log".to_string(),
104 max_packets_per_file: sys_prop::get_u32("persist.bluetooth.btsnoopsize")
105 .unwrap_or(0xFFFF),
106 mode: get_configured_snoop_mode().parse().unwrap_or(SnoopMode::Disabled),
107 }
108 }
109
110 /// Overwrites the laoded log path with the provided one
set_path(&mut self, value: String)111 pub fn set_path(&mut self, value: String) {
112 self.path = value;
113 }
114
115 /// Overwrites the loaded mode with the provided one
set_mode(&mut self, value: SnoopMode)116 pub fn set_mode(&mut self, value: SnoopMode) {
117 self.mode = value;
118 }
119 }
120
121 impl Default for SnoopConfig {
default() -> Self122 fn default() -> Self {
123 Self::new()
124 }
125 }
126
get_configured_snoop_mode() -> String127 fn get_configured_snoop_mode() -> String {
128 sys_prop::get("persist.bluetooth.btsnooplogmode").unwrap_or(if sys_prop::get_debuggable() {
129 sys_prop::get("persist.bluetooth.btsnoopdefaultmode").unwrap_or_default()
130 } else {
131 String::default()
132 })
133 }
134
135 module! {
136 snoop_module,
137 providers {
138 parts Hal => provide_snooped_hal,
139 },
140 }
141
142 #[provides]
provide_snooped_hal(config: SnoopConfig, raw_hal: RawHal, rt: Arc<Runtime>) -> Hal143 async fn provide_snooped_hal(config: SnoopConfig, raw_hal: RawHal, rt: Arc<Runtime>) -> Hal {
144 let (cmd_down_tx, mut cmd_down_rx) = channel::<CommandPacket>(10);
145 let (evt_up_tx, evt_up_rx) = channel::<EventPacket>(10);
146 let (acl_down_tx, mut acl_down_rx) = channel::<AclPacket>(10);
147 let (acl_up_tx, acl_up_rx) = channel::<AclPacket>(10);
148 let (sco_down_tx, mut sco_down_rx) = channel::<ScoPacket>(10);
149 let (sco_up_tx, sco_up_rx) = channel::<ScoPacket>(10);
150 let (iso_down_tx, mut iso_down_rx) = channel::<IsoPacket>(10);
151 let (iso_up_tx, iso_up_rx) = channel::<IsoPacket>(10);
152
153 rt.spawn(async move {
154 let mut logger = SnoopLogger::new(config).await;
155 loop {
156 select! {
157 Some(evt) = consume(&raw_hal.evt_rx) => {
158 if let Err(e) = evt_up_tx.send(evt.clone()).await {
159 error!("evt channel closed {:?}", e);
160 break;
161 }
162 logger.log(Type::Evt, Direction::Up, evt.to_bytes()).await;
163 },
164 Some(cmd) = cmd_down_rx.recv() => {
165 if let Err(e) = raw_hal.cmd_tx.send(cmd.clone()) {
166 error!("cmd channel closed {:?}", e);
167 break;
168 }
169 logger.log(Type::Cmd, Direction::Down, cmd.to_bytes()).await;
170 },
171 Some(acl) = acl_down_rx.recv() => {
172 if let Err(e) = raw_hal.acl_tx.send(acl.clone()) {
173 error!("acl down channel closed {:?}", e);
174 break;
175 }
176 logger.log(Type::Acl, Direction::Down, acl.to_bytes()).await;
177 },
178 Some(acl) = consume(&raw_hal.acl_rx) => {
179 if let Err(e) = acl_up_tx.send(acl.clone()).await {
180 error!("acl up channel closed {:?}", e);
181 break;
182 }
183 logger.log(Type::Acl, Direction::Up, acl.to_bytes()).await;
184 },
185 Some(sco) = sco_down_rx.recv() => {
186 if let Err(e) = raw_hal.sco_tx.send(sco.clone()) {
187 error!("sco down channel closed {:?}", e);
188 break;
189 }
190 logger.log(Type::Sco, Direction::Down, sco.to_bytes()).await;
191 },
192 Some(sco) = consume(&raw_hal.sco_rx) => {
193 if let Err(e) = sco_up_tx.send(sco.clone()).await {
194 error!("sco up channel closed {:?}", e);
195 break;
196 }
197 logger.log(Type::Sco, Direction::Up, sco.to_bytes()).await;
198 },
199 Some(iso) = iso_down_rx.recv() => {
200 if let Err(e) = raw_hal.iso_tx.send(iso.clone()) {
201 error!("iso down channel closed {:?}", e);
202 break;
203 }
204 logger.log(Type::Iso, Direction::Down, iso.to_bytes()).await;
205 },
206 Some(iso) = consume(&raw_hal.iso_rx) => {
207 if let Err(e) = iso_up_tx.send(iso.clone()).await {
208 error!("iso up channel closed {:?}", e);
209 break;
210 }
211 logger.log(Type::Iso, Direction::Up, iso.to_bytes()).await;
212 },
213 else => break,
214 }
215 }
216 });
217
218 Hal {
219 control: ControlHal { tx: cmd_down_tx, rx: Arc::new(Mutex::new(evt_up_rx)) },
220 acl: AclHal { tx: acl_down_tx, rx: Arc::new(Mutex::new(acl_up_rx)) },
221 sco: ScoHal { tx: sco_down_tx, rx: Arc::new(Mutex::new(sco_up_rx)) },
222 iso: IsoHal { tx: iso_down_tx, rx: Arc::new(Mutex::new(iso_up_rx)) },
223 }
224 }
225
consume<T>(rx: &Arc<Mutex<UnboundedReceiver<T>>>) -> Option<T>226 async fn consume<T>(rx: &Arc<Mutex<UnboundedReceiver<T>>>) -> Option<T> {
227 rx.lock().await.recv().await
228 }
229
230 #[allow(unused)]
231 enum Type {
232 Cmd = 1,
233 Acl,
234 Sco,
235 Evt,
236 Iso,
237 }
238
239 enum Direction {
240 Up,
241 Down,
242 }
243
244 struct SnoopLogger {
245 config: SnoopConfig,
246 file: Option<File>,
247 packets: u32,
248 }
249
250 // micros since 0000-01-01
251 const SNOOP_EPOCH_DELTA: u64 = 0x00dcddb30f2f8000;
252
253 impl SnoopLogger {
new(mut config: SnoopConfig) -> Self254 async fn new(mut config: SnoopConfig) -> Self {
255 // filtered snoop is not available at this time
256 if let SnoopMode::Filtered = config.mode {
257 config.mode = SnoopMode::Disabled;
258 }
259
260 remove_file(&config.path).await.ok();
261 remove_file(config.path.clone() + ".last").await.ok();
262 if let SnoopMode::Disabled = config.mode {
263 remove_file(config.path.clone() + ".filtered").await.ok();
264 remove_file(config.path.clone() + ".filtered.last").await.ok();
265 }
266
267 let mut ret = Self { config, file: None, packets: 0 };
268 ret.open_next_file().await;
269
270 ret
271 }
272
log(&mut self, t: Type, dir: Direction, bytes: Bytes)273 async fn log(&mut self, t: Type, dir: Direction, bytes: Bytes) {
274 if let SnoopMode::Disabled = self.config.mode {
275 return;
276 }
277
278 let mut flags = 0;
279 if let Direction::Up = dir {
280 flags |= 0b01;
281 }
282 if let Type::Cmd | Type::Evt = t {
283 flags |= 0b10;
284 }
285
286 let timestamp: u64 = u64::try_from(
287 SystemTime::now().duration_since(SystemTime::UNIX_EPOCH).unwrap().as_micros(),
288 )
289 .unwrap()
290 + SNOOP_EPOCH_DELTA;
291
292 // Add one for the type byte
293 let length = u32::try_from(bytes.len()).unwrap() + 1;
294
295 let mut buffer = BytesMut::new();
296 buffer.put_u32(length); // original length
297 buffer.put_u32(length); // captured length
298 buffer.put_u32(flags); // flags
299 buffer.put_u32(0); // dropped packets
300 buffer.put_u64(timestamp); // timestamp
301 buffer.put_u8(t as u8); // type
302 buffer.put(bytes);
303
304 self.packets += 1;
305 if self.packets > self.config.max_packets_per_file {
306 self.open_next_file().await;
307 }
308
309 if let Some(file) = &mut self.file {
310 if file.write_all(&buffer).await.is_err() {
311 error!("Failed to write");
312 }
313 if file.flush().await.is_err() {
314 error!("Failed to flush");
315 }
316 } else {
317 panic!("Logging without a backing file");
318 }
319 }
320
close_file(&mut self)321 async fn close_file(&mut self) {
322 if let Some(file) = &mut self.file {
323 file.flush().await.ok();
324 self.file = None;
325 }
326 self.packets = 0;
327 }
328
open_next_file(&mut self)329 async fn open_next_file(&mut self) {
330 self.close_file().await;
331
332 rename(&self.config.path, self.config.path.clone() + ".last").await.ok();
333 let mut file = File::create(&self.config.path).await.expect("could not open snoop log");
334 file.write_all(b"btsnoop\x00\x00\x00\x00\x01\x00\x00\x03\xea")
335 .await
336 .expect("could not write snoop header");
337 if file.flush().await.is_err() {
338 error!("Failed to flush");
339 }
340 self.file = Some(file);
341 }
342 }
343