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