1 /*
2  * Copyright 2019 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 #include "hal/snoop_logger.h"
18 
19 #include <arpa/inet.h>
20 #include <bluetooth/log.h>
21 #include <sys/stat.h>
22 
23 #include <algorithm>
24 #include <bitset>
25 #include <chrono>
26 #include <sstream>
27 
28 #include "common/circular_buffer.h"
29 #include "common/init_flags.h"
30 #include "common/strings.h"
31 #include "hal/snoop_logger_common.h"
32 #include "module_dumper_flatbuffer.h"
33 #include "os/files.h"
34 #include "os/log.h"
35 #include "os/parameter_provider.h"
36 #include "os/system_properties.h"
37 
38 #ifdef USE_FAKE_TIMERS
39 #include "os/fake_timer/fake_timerfd.h"
40 using bluetooth::os::fake_timer::fake_timerfd_get_clock;
41 #endif
42 
43 namespace bluetooth {
44 namespace hal {
45 
46 // Adds L2CAP channel to acceptlist.
AddL2capCid(uint16_t local_cid,uint16_t remote_cid)47 void FilterTracker::AddL2capCid(uint16_t local_cid, uint16_t remote_cid) {
48   l2c_local_cid.insert(local_cid);
49   l2c_remote_cid.insert(remote_cid);
50 }
51 
52 // Sets L2CAP channel that RFCOMM uses.
SetRfcommCid(uint16_t local_cid,uint16_t remote_cid)53 void FilterTracker::SetRfcommCid(uint16_t local_cid, uint16_t remote_cid) {
54   rfcomm_local_cid = local_cid;
55   rfcomm_remote_cid = remote_cid;
56 }
57 
58 // Remove L2CAP channel from acceptlist.
RemoveL2capCid(uint16_t local_cid,uint16_t remote_cid)59 void FilterTracker::RemoveL2capCid(uint16_t local_cid, uint16_t remote_cid) {
60   if (rfcomm_local_cid == local_cid) {
61     rfcomm_channels.clear();
62     rfcomm_channels.insert(0);
63     rfcomm_local_cid = 0;
64     rfcomm_remote_cid = 0;
65   }
66 
67   l2c_local_cid.erase(local_cid);
68   l2c_remote_cid.erase(remote_cid);
69 }
70 
AddRfcommDlci(uint8_t channel)71 void FilterTracker::AddRfcommDlci(uint8_t channel) {
72   rfcomm_channels.insert(channel);
73 }
74 
IsAcceptlistedL2cap(bool local,uint16_t cid)75 bool FilterTracker::IsAcceptlistedL2cap(bool local, uint16_t cid) {
76   const auto& set = local ? l2c_local_cid : l2c_remote_cid;
77   return (set.find(cid) != set.end());
78 }
79 
IsRfcommChannel(bool local,uint16_t cid)80 bool FilterTracker::IsRfcommChannel(bool local, uint16_t cid) {
81   const auto& channel = local ? rfcomm_local_cid : rfcomm_remote_cid;
82   return cid == channel;
83 }
84 
IsAcceptlistedDlci(uint8_t dlci)85 bool FilterTracker::IsAcceptlistedDlci(uint8_t dlci) {
86   return rfcomm_channels.find(dlci) != rfcomm_channels.end();
87 }
88 
SetupProfilesFilter(bool pbap_filtered,bool map_filtered)89 void ProfilesFilter::SetupProfilesFilter(bool pbap_filtered, bool map_filtered) {
90   if (setup_done_flag) {
91     return;
92   }
93   setup_done_flag = true;
94 
95   log::debug("SetupProfilesFilter: pbap={}, map={}", pbap_filtered, map_filtered);
96 
97   for (int i = 0; i < FILTER_PROFILE_MAX; i++) {
98     profiles[i].type = (profile_type_t)i;
99     profiles[i].enabled = false;
100     profiles[i].rfcomm_opened = false;
101     profiles[i].l2cap_opened = false;
102   }
103 
104   if (pbap_filtered) {
105     profiles[FILTER_PROFILE_PBAP].enabled = profiles[FILTER_PROFILE_HFP_HS].enabled =
106         profiles[FILTER_PROFILE_HFP_HF].enabled = true;
107   }
108   if (map_filtered) {
109     profiles[FILTER_PROFILE_MAP].enabled = true;
110   }
111   ch_rfc_l = ch_rfc_r = ch_last = 0;
112 
113   PrintProfilesConfig();
114 }
115 
IsHfpProfile(bool local,uint16_t cid,uint8_t dlci)116 bool ProfilesFilter::IsHfpProfile(bool local, uint16_t cid, uint8_t dlci) {
117   profile_type_t profile = DlciToProfile(local, cid, dlci);
118   return profile == FILTER_PROFILE_HFP_HS || profile == FILTER_PROFILE_HFP_HF;
119 }
120 
IsL2capFlowExt(bool local,uint16_t cid)121 bool ProfilesFilter::IsL2capFlowExt(bool local, uint16_t cid) {
122   profile_type_t profile = CidToProfile(local, cid);
123   if (profile >= 0) return profiles[profile].flow_ext_l2cap;
124   return false;
125 }
126 
IsRfcommFlowExt(bool local,uint16_t cid,uint8_t dlci)127 bool ProfilesFilter::IsRfcommFlowExt(bool local, uint16_t cid, uint8_t dlci) {
128   profile_type_t profile = DlciToProfile(local, cid, dlci);
129   if (profile >= 0) current_profile = profile;
130   return profiles[profile].flow_ext_rfcomm;
131 }
132 
CidToProfile(bool local,uint16_t cid)133 profile_type_t ProfilesFilter::CidToProfile(bool local, uint16_t cid) {
134   uint16_t ch;
135   for (int i = 0; i < FILTER_PROFILE_MAX; i++) {
136     if (profiles[i].enabled && profiles[i].l2cap_opened) {
137       ch = local ? profiles[i].lcid : profiles[i].rcid;
138       if (ch == cid) {
139         return (profile_type_t)i;
140       }
141     }
142   }
143   return FILTER_PROFILE_NONE;
144 }
145 
DlciToProfile(bool local,uint16_t cid,uint8_t dlci)146 profile_type_t ProfilesFilter::DlciToProfile(bool local, uint16_t cid, uint8_t dlci) {
147   if (!IsRfcommChannel(local, cid)) return FILTER_PROFILE_NONE;
148 
149   for (int i = 0; i < FILTER_PROFILE_MAX; i++) {
150     if (profiles[i].enabled && profiles[i].l2cap_opened && profiles[i].rfcomm_opened &&
151         profiles[i].scn == (dlci >> 1)) {
152       return (profile_type_t)i;
153     }
154   }
155   return FILTER_PROFILE_NONE;
156 }
157 
ProfileL2capOpen(profile_type_t profile,uint16_t lcid,uint16_t rcid,uint16_t psm,bool flow_ext)158 void ProfilesFilter::ProfileL2capOpen(
159     profile_type_t profile, uint16_t lcid, uint16_t rcid, uint16_t psm, bool flow_ext) {
160   if (profiles[profile].l2cap_opened == true) {
161     log::debug("l2cap for {} was already opened. Override it", profile);
162   }
163   log::debug(
164       "lcid:={}, rcid={}, psm={}, flow_ext={}, filter profile={}",
165       lcid,
166       rcid,
167       psm,
168       flow_ext,
169       ProfilesFilter::ProfileToString(profile));
170   profiles[profile].lcid = lcid;
171   profiles[profile].rcid = rcid;
172   profiles[profile].psm = psm;
173   profiles[profile].flow_ext_l2cap = flow_ext;
174   profiles[profile].l2cap_opened = true;
175 
176   PrintProfilesConfig();
177 }
178 
ProfileL2capClose(profile_type_t profile)179 void ProfilesFilter::ProfileL2capClose(profile_type_t profile) {
180   if (profile < 0 || profile >= FILTER_PROFILE_MAX) return;
181   profiles[profile].l2cap_opened = false;
182 }
183 
ProfileRfcommOpen(profile_type_t profile,uint16_t lcid,uint8_t dlci,uint16_t uuid,bool flow_ext)184 void ProfilesFilter::ProfileRfcommOpen(
185     profile_type_t profile, uint16_t lcid, uint8_t dlci, uint16_t uuid, bool flow_ext) {
186   if (profiles[profile].rfcomm_opened == true) {
187     log::debug("rfcomm for {} was already opened. Override it", profile);
188   }
189   log::debug(
190       "lcid:={}, dlci={}, uuid={}, flow_ext={}, filter profile={}",
191       lcid,
192       dlci,
193       uuid,
194       flow_ext,
195       ProfilesFilter::ProfileToString(profile));
196   profiles[profile].rfcomm_uuid = uuid;
197   profiles[profile].scn = (dlci >> 1);
198   profiles[profile].flow_ext_rfcomm = flow_ext;
199   profiles[profile].l2cap_opened = true;
200   profiles[profile].rfcomm_opened = true;
201 
202   PrintProfilesConfig();
203 }
204 
ProfileRfcommClose(profile_type_t profile)205 void ProfilesFilter::ProfileRfcommClose(profile_type_t profile) {
206   if (profile < 0 || profile >= FILTER_PROFILE_MAX) return;
207   profiles[profile].rfcomm_opened = false;
208 }
209 
IsRfcommChannel(bool local,uint16_t cid)210 bool ProfilesFilter::IsRfcommChannel(bool local, uint16_t cid) {
211   uint16_t channel = local ? ch_rfc_l : ch_rfc_r;
212   return cid == channel;
213 }
214 
PrintProfilesConfig()215 void ProfilesFilter::PrintProfilesConfig() {
216   for (int i = 0; i < FILTER_PROFILE_MAX; i++) {
217     if (profiles[i].enabled) {
218       log::debug(
219           "\ntype: {}\nenabled: {}, l2cap_opened: {}, rfcomm_opened: {}\nflow_ext_l2cap: {}, "
220           "flow_ext_rfcomm: {}\nlcid: {}, rcid: {}, rfcomm_uuid: {}, psm: {}\nscn: {}\n",
221           ProfilesFilter::ProfileToString(profiles[i].type),
222           profiles[i].enabled,
223           profiles[i].l2cap_opened,
224           profiles[i].rfcomm_opened,
225           profiles[i].flow_ext_l2cap,
226           profiles[i].flow_ext_rfcomm,
227           profiles[i].lcid,
228           profiles[i].rcid,
229           profiles[i].rfcomm_uuid,
230           profiles[i].psm,
231           profiles[i].psm);
232     }
233   }
234 }
235 
236 namespace {
237 
238 // Epoch in microseconds since 01/01/0000.
239 constexpr uint64_t kBtSnoopEpochDelta = 0x00dcddb30f2f8000ULL;
240 
241 // Qualcomm debug logs handle
242 constexpr uint16_t kQualcommDebugLogHandle = 0xedc;
243 
244 // Number of bytes into a packet where you can find the value for a channel.
245 constexpr size_t ACL_CHANNEL_OFFSET = 0;
246 constexpr size_t ACL_LENGTH_OFFSET = 2;
247 constexpr size_t L2CAP_PDU_LENGTH_OFFSET = 4;
248 constexpr size_t L2CAP_CHANNEL_OFFSET = 6;
249 constexpr size_t L2CAP_CONTROL_OFFSET = 8;
250 constexpr size_t RFCOMM_CHANNEL_OFFSET = 8;
251 constexpr size_t RFCOMM_EVENT_OFFSET = 9;
252 
253 // RFCOMM filtering consts
254 constexpr uint8_t RFCOMM_SABME = 0x2F;  // RFCOMM: Start Asynchronous Balanced Mode (startup cmd)
255 constexpr uint8_t RFCOMM_UA = 0x63;     // RFCOMM: Unnumbered Acknowledgement (rsp when connected)
256 constexpr uint8_t RFCOMM_UIH = 0xEF;    // RFCOMM: Unnumbered Information with Header check
257 
258 constexpr uint8_t START_PACKET_BOUNDARY = 0x02;
259 constexpr uint8_t CONTINUATION_PACKET_BOUNDARY = 0x01;
260 constexpr uint16_t HANDLE_MASK = 0x0FFF;
__anon184083ae0202(auto handle) 261 auto GetBoundaryFlag = [](auto handle) { return (((handle) >> 12) & 0x0003); };
262 
263 // ProfilesFilter consts
264 constexpr size_t ACL_HEADER_LENGTH = 4;
265 constexpr size_t BASIC_L2CAP_HEADER_LENGTH = 4;
266 constexpr uint8_t EXTRA_BUF_SIZE = 0x40;
267 constexpr uint16_t DEFAULT_PACKET_SIZE = 0x800;
268 
269 constexpr uint8_t PROFILE_SCN_PBAP = 19;
270 constexpr uint8_t PROFILE_SCN_MAP = 26;
271 
272 constexpr uint16_t PROFILE_PSM_PBAP = 0x1025;
273 constexpr uint16_t PROFILE_PSM_MAP = 0x1029;
274 constexpr uint16_t PROFILE_PSM_RFCOMM = 0x0003;
275 
276 constexpr uint16_t PROFILE_UUID_PBAP = 0x112f;
277 constexpr uint16_t PROFILE_UUID_MAP = 0x1132;
278 constexpr uint16_t PROFILE_UUID_HFP_HS = 0x1112;
279 constexpr uint16_t PROFILE_UUID_HFP_HF = 0x111f;
280 
htonll(uint64_t ll)281 uint64_t htonll(uint64_t ll) {
282   if constexpr (isLittleEndian) {
283     return static_cast<uint64_t>(htonl(ll & 0xffffffff)) << 32 | htonl(ll >> 32);
284   } else {
285     return ll;
286   }
287 }
288 
289 // The number of packets per btsnoop file before we rotate to the next file. As of right now there
290 // are two snoop files that are rotated through. The size can be dynamically configured by setting
291 // the relevant system property
292 constexpr size_t kDefaultBtSnoopMaxPacketsPerFile = 0xffff;
293 
294 // We restrict the maximum packet size to 150 bytes
295 constexpr size_t kDefaultBtSnoozMaxBytesPerPacket = 150;
296 constexpr size_t kDefaultBtSnoozMaxPayloadBytesPerPacket =
297     kDefaultBtSnoozMaxBytesPerPacket - sizeof(SnoopLogger::PacketHeaderType);
298 
299 using namespace std::chrono_literals;
300 constexpr std::chrono::hours kBtSnoozLogLifeTime = 12h;
301 constexpr std::chrono::hours kBtSnoozLogDeleteRepeatingAlarmInterval = 1h;
302 
303 std::mutex filter_tracker_list_mutex;
304 std::unordered_map<uint16_t, FilterTracker> filter_tracker_list;
305 std::unordered_map<uint16_t, uint16_t> local_cid_to_acl;
306 
307 std::mutex a2dpMediaChannels_mutex;
308 std::vector<SnoopLogger::A2dpMediaChannel> a2dpMediaChannels;
309 
310 std::mutex snoop_log_filters_mutex;
311 
312 std::mutex profiles_filter_mutex;
313 std::unordered_map<int16_t, ProfilesFilter> profiles_filter_table;
314 constexpr const char* payload_fill_magic = "PROHIBITED";
315 constexpr const char* cpbr_pattern = "\x0d\x0a+CPBR:";
316 constexpr const char* clcc_pattern = "\x0d\x0a+CLCC:";
317 const uint32_t magic_pat_len = strlen(payload_fill_magic);
318 const uint32_t cpbr_pat_len = strlen(cpbr_pattern);
319 const uint32_t clcc_pat_len = strlen(clcc_pattern);
320 
get_btsnoop_log_path(std::string log_dir,bool filtered)321 std::string get_btsnoop_log_path(std::string log_dir, bool filtered) {
322   if (filtered) {
323     log_dir.append(".filtered");
324   }
325   return log_dir;
326 }
327 
get_last_log_path(std::string log_file_path)328 std::string get_last_log_path(std::string log_file_path) {
329   return log_file_path.append(".last");
330 }
331 
delete_btsnoop_files(const std::string & log_path)332 void delete_btsnoop_files(const std::string& log_path) {
333   log::info("Deleting logs if they exist");
334   if (os::FileExists(log_path)) {
335     if (!os::RemoveFile(log_path)) {
336       log::error("Failed to remove main log file at \"{}\"", log_path);
337     }
338   } else {
339     log::info("Main log file does not exist at \"{}\"", log_path);
340   }
341   auto last_log_path = get_last_log_path(log_path);
342   if (os::FileExists(last_log_path)) {
343     if (!os::RemoveFile(last_log_path)) {
344       log::error("Failed to remove last log file at \"{}\"", log_path);
345     }
346   } else {
347     log::info("Last log file does not exist at \"{}\"", log_path);
348   }
349 }
350 
delete_old_btsnooz_files(const std::string & log_path,const std::chrono::milliseconds log_life_time)351 void delete_old_btsnooz_files(const std::string& log_path, const std::chrono::milliseconds log_life_time) {
352   auto opt_created_ts = os::FileCreatedTime(log_path);
353   if (!opt_created_ts) return;
354 #ifdef USE_FAKE_TIMERS
355   auto diff = fake_timerfd_get_clock() - file_creation_time;
356   uint64_t log_lifetime = log_life_time.count();
357   if (diff >= log_lifetime) {
358 #else
359   using namespace std::chrono;
360   auto created_tp = opt_created_ts.value();
361   auto current_tp = std::chrono::system_clock::now();
362 
363   auto diff = duration_cast<milliseconds>(current_tp - created_tp);
364   if (diff >= log_life_time) {
365 #endif
366     delete_btsnoop_files(log_path);
367   }
368 }
369 
370 size_t get_btsnooz_packet_length_to_write(
371     const HciPacket& packet, SnoopLogger::PacketType type, bool qualcomm_debug_log_enabled) {
372   static const size_t kAclHeaderSize = 4;
373   static const size_t kL2capHeaderSize = 4;
374   static const size_t kL2capCidOffset = (kAclHeaderSize + 2);
375   static const uint16_t kL2capSignalingCid = 0x0001;
376 
377   static const size_t kHciAclHandleOffset = 0;
378 
379   // Maximum amount of ACL data to log.
380   // Enough for an RFCOMM frame up to the frame check;
381   // not enough for a HID report or audio data.
382   static const size_t kMaxBtsnoozAclSize = 14;
383 
384   // Calculate packet length to be included
385   size_t included_length = 0;
386   switch (type) {
387     case SnoopLogger::PacketType::CMD:
388     case SnoopLogger::PacketType::EVT:
389       included_length = packet.size();
390       break;
391 
392     case SnoopLogger::PacketType::ACL: {
393       // Log ACL and L2CAP header by default
394       size_t len_hci_acl = kAclHeaderSize + kL2capHeaderSize;
395       // Check if we have enough data for an L2CAP header
396       if (packet.size() > len_hci_acl) {
397         uint16_t l2cap_cid =
398             static_cast<uint16_t>(packet[kL2capCidOffset]) |
399             static_cast<uint16_t>((static_cast<uint16_t>(packet[kL2capCidOffset + 1]) << static_cast<uint16_t>(8)));
400         uint16_t hci_acl_packet_handle =
401             static_cast<uint16_t>(packet[kHciAclHandleOffset]) |
402             static_cast<uint16_t>((static_cast<uint16_t>(packet[kHciAclHandleOffset + 1]) << static_cast<uint16_t>(8)));
403         hci_acl_packet_handle &= 0x0fff;
404 
405         if (l2cap_cid == kL2capSignalingCid) {
406           // For the signaling CID, take the full packet.
407           // That way, the PSM setup is captured, allowing decoding of PSMs down
408           // the road.
409           return packet.size();
410         } else if (qualcomm_debug_log_enabled && hci_acl_packet_handle == kQualcommDebugLogHandle) {
411           return packet.size();
412         } else {
413           // Otherwise, return as much as we reasonably can
414           len_hci_acl = kMaxBtsnoozAclSize;
415         }
416       }
417       included_length = std::min(len_hci_acl, packet.size());
418       break;
419     }
420 
421     case SnoopLogger::PacketType::ISO:
422     case SnoopLogger::PacketType::SCO:
423     default:
424       // We are not logging SCO and ISO packets in snooz log as they may contain voice data
425       break;
426   }
427   return std::min(included_length, kDefaultBtSnoozMaxPayloadBytesPerPacket);
428 }
429 
430 }  // namespace
431 
432 // system properties
433 const std::string SnoopLogger::kBtSnoopMaxPacketsPerFileProperty = "persist.bluetooth.btsnoopsize";
434 const std::string SnoopLogger::kIsDebuggableProperty = "ro.debuggable";
435 const std::string SnoopLogger::kBtSnoopLogModeProperty = "persist.bluetooth.btsnooplogmode";
436 const std::string SnoopLogger::kBtSnoopDefaultLogModeProperty = "persist.bluetooth.btsnoopdefaultmode";
437 const std::string SnoopLogger::kBtSnoopLogPersists = "persist.bluetooth.btsnooplogpersists";
438 // Truncates ACL packets (non-fragment) to fixed (MAX_HCI_ACL_LEN) number of bytes
439 const std::string SnoopLogger::kBtSnoopLogFilterHeadersProperty =
440     "persist.bluetooth.snooplogfilter.headers.enabled";
441 // Discards A2DP media packets (non-split mode)
442 const std::string SnoopLogger::kBtSnoopLogFilterProfileA2dpProperty =
443     "persist.bluetooth.snooplogfilter.profiles.a2dp.enabled";
444 // Filters MAP packets based on the filter mode
445 const std::string SnoopLogger::kBtSnoopLogFilterProfileMapModeProperty =
446     "persist.bluetooth.snooplogfilter.profiles.map";
447 // Filters PBAP and HFP packets (CPBR, CLCC) based on the filter mode
448 const std::string SnoopLogger::kBtSnoopLogFilterProfilePbapModeProperty =
449     "persist.bluetooth.snooplogfilter.profiles.pbap";
450 // Truncates RFCOMM UIH packet to fixed (L2CAP_HEADER_SIZE) number of bytes
451 const std::string SnoopLogger::kBtSnoopLogFilterProfileRfcommProperty =
452     "persist.bluetooth.snooplogfilter.profiles.rfcomm.enabled";
453 const std::string SnoopLogger::kSoCManufacturerProperty = "ro.soc.manufacturer";
454 
455 // persist.bluetooth.btsnooplogmode
456 const std::string SnoopLogger::kBtSnoopLogModeDisabled = "disabled";
457 const std::string SnoopLogger::kBtSnoopLogModeFiltered = "filtered";
458 const std::string SnoopLogger::kBtSnoopLogModeFull = "full";
459 // ro.soc.manufacturer
460 const std::string SnoopLogger::kSoCManufacturerQualcomm = "Qualcomm";
461 
462 // PBAP, MAP and HFP packets filter mode - discard whole packet
463 const std::string SnoopLogger::kBtSnoopLogFilterProfileModeFullfillter = "fullfilter";
464 // PBAP, MAP and HFP packets filter mode - truncate to fixed length
465 const std::string SnoopLogger::kBtSnoopLogFilterProfileModeHeader = "header";
466 // PBAP, MAP and HFP packets filter mode - fill with a magic string, such as: "PROHIBITED"
467 const std::string SnoopLogger::kBtSnoopLogFilterProfileModeMagic = "magic";
468 // PBAP, MAP and HFP packets filter mode - disabled
469 const std::string SnoopLogger::kBtSnoopLogFilterProfileModeDisabled = "disabled";
470 
471 std::string SnoopLogger::btsnoop_mode_;
472 
473 // Consts accessible in unit tests
474 const size_t SnoopLogger::PACKET_TYPE_LENGTH = 1;
475 const size_t SnoopLogger::MAX_HCI_ACL_LEN = 14;
476 const uint32_t SnoopLogger::L2CAP_HEADER_SIZE = 8;
477 
SnoopLogger(std::string snoop_log_path,std::string snooz_log_path,size_t max_packets_per_file,size_t max_packets_per_buffer,const std::string & btsnoop_mode,bool qualcomm_debug_log_enabled,const std::chrono::milliseconds snooz_log_life_time,const std::chrono::milliseconds snooz_log_delete_alarm_interval,bool snoop_log_persists)478 SnoopLogger::SnoopLogger(
479     std::string snoop_log_path,
480     std::string snooz_log_path,
481     size_t max_packets_per_file,
482     size_t max_packets_per_buffer,
483     const std::string& btsnoop_mode,
484     bool qualcomm_debug_log_enabled,
485     const std::chrono::milliseconds snooz_log_life_time,
486     const std::chrono::milliseconds snooz_log_delete_alarm_interval,
487     bool snoop_log_persists)
488     : snoop_log_path_(std::move(snoop_log_path)),
489       snooz_log_path_(std::move(snooz_log_path)),
490       max_packets_per_file_(max_packets_per_file),
491       btsnooz_buffer_(max_packets_per_buffer),
492       qualcomm_debug_log_enabled_(qualcomm_debug_log_enabled),
493       snooz_log_life_time_(snooz_log_life_time),
494       snooz_log_delete_alarm_interval_(snooz_log_delete_alarm_interval),
495       snoop_log_persists(snoop_log_persists) {
496   btsnoop_mode_ = btsnoop_mode;
497 
498   if (btsnoop_mode_ == kBtSnoopLogModeFiltered) {
499     log::info("Snoop Logs filtered mode enabled");
500     EnableFilters();
501     // delete unfiltered logs
502     delete_btsnoop_files(get_btsnoop_log_path(snoop_log_path_, false));
503     // delete snooz logs
504     delete_btsnoop_files(snooz_log_path_);
505   } else if (btsnoop_mode_ == kBtSnoopLogModeFull) {
506     log::info("Snoop Logs full mode enabled");
507     if (!snoop_log_persists) {
508       // delete filtered logs
509       delete_btsnoop_files(get_btsnoop_log_path(snoop_log_path_, true));
510       // delete snooz logs
511       delete_btsnoop_files(snooz_log_path_);
512     }
513   } else {
514     log::info("Snoop Logs disabled");
515     // delete both filtered and unfiltered logs
516     delete_btsnoop_files(get_btsnoop_log_path(snoop_log_path_, true));
517     delete_btsnoop_files(get_btsnoop_log_path(snoop_log_path_, false));
518   }
519 
520   snoop_logger_socket_thread_ = nullptr;
521   socket_ = nullptr;
522   // Add ".filtered" extension if necessary
523   snoop_log_path_ = get_btsnoop_log_path(snoop_log_path_, btsnoop_mode_ == kBtSnoopLogModeFiltered);
524 }
525 
CloseCurrentSnoopLogFile()526 void SnoopLogger::CloseCurrentSnoopLogFile() {
527   std::lock_guard<std::recursive_mutex> lock(file_mutex_);
528   if (btsnoop_ostream_.is_open()) {
529     btsnoop_ostream_.flush();
530     btsnoop_ostream_.close();
531   }
532   packet_counter_ = 0;
533 }
534 
OpenNextSnoopLogFile()535 void SnoopLogger::OpenNextSnoopLogFile() {
536   std::lock_guard<std::recursive_mutex> lock(file_mutex_);
537   CloseCurrentSnoopLogFile();
538 
539   auto last_file_path = get_last_log_path(snoop_log_path_);
540 
541   if (os::FileExists(snoop_log_path_)) {
542     if (!os::RenameFile(snoop_log_path_, last_file_path)) {
543       log::error(
544           "Unabled to rename existing snoop log from \"{}\" to \"{}\"",
545           snoop_log_path_,
546           last_file_path);
547     }
548   } else {
549     log::info("Previous log file \"{}\" does not exist, skip renaming", snoop_log_path_);
550   }
551 
552   mode_t prevmask = umask(0);
553   // do not use std::ios::app as we want override the existing file
554   btsnoop_ostream_.open(snoop_log_path_, std::ios::binary | std::ios::out);
555 #ifdef USE_FAKE_TIMERS
556   file_creation_time = fake_timerfd_get_clock();
557 #endif
558   if (!btsnoop_ostream_.good()) {
559     log::fatal(
560         "Unable to open snoop log at \"{}\", error: \"{}\"", snoop_log_path_, strerror(errno));
561   }
562   umask(prevmask);
563   if (!btsnoop_ostream_.write(
564           reinterpret_cast<const char*>(&SnoopLoggerCommon::kBtSnoopFileHeader),
565           sizeof(SnoopLoggerCommon::FileHeaderType))) {
566     log::fatal(
567         "Unable to write file header to \"{}\", error: \"{}\"", snoop_log_path_, strerror(errno));
568   }
569   if (!btsnoop_ostream_.flush()) {
570     log::error("Failed to flush, error: \"{}\"", strerror(errno));
571   }
572 }
573 
EnableFilters()574 void SnoopLogger::EnableFilters() {
575   if (btsnoop_mode_ != kBtSnoopLogModeFiltered) {
576     return;
577   }
578   std::lock_guard<std::mutex> lock(snoop_log_filters_mutex);
579   for (auto itr = kBtSnoopLogFilterState.begin(); itr != kBtSnoopLogFilterState.end(); itr++) {
580     auto filter_enabled_property = os::GetSystemProperty(itr->first);
581     if (filter_enabled_property) {
582       itr->second = filter_enabled_property.value() == "true";
583     }
584     log::info("{}: {}", itr->first, itr->second);
585   }
586   for (auto itr = kBtSnoopLogFilterMode.begin(); itr != kBtSnoopLogFilterMode.end(); itr++) {
587     auto filter_mode_property = os::GetSystemProperty(itr->first);
588     if (filter_mode_property) {
589       itr->second = filter_mode_property.value();
590     } else {
591       itr->second = SnoopLogger::kBtSnoopLogFilterProfileModeDisabled;
592     }
593     log::info("{}: {}", itr->first, itr->second);
594   }
595 }
596 
DisableFilters()597 void SnoopLogger::DisableFilters() {
598   std::lock_guard<std::mutex> lock(snoop_log_filters_mutex);
599   for (auto itr = kBtSnoopLogFilterState.begin(); itr != kBtSnoopLogFilterState.end(); itr++) {
600     itr->second = false;
601     log::info("{}, {}", itr->first, itr->second);
602   }
603   for (auto itr = kBtSnoopLogFilterMode.begin(); itr != kBtSnoopLogFilterMode.end(); itr++) {
604     itr->second = SnoopLogger::kBtSnoopLogFilterProfileModeDisabled;
605     log::info("{}, {}", itr->first, itr->second);
606   }
607 }
608 
IsFilterEnabled(std::string filter_name)609 bool SnoopLogger::IsFilterEnabled(std::string filter_name) {
610   std::lock_guard<std::mutex> lock(snoop_log_filters_mutex);
611   for (auto itr = kBtSnoopLogFilterState.begin(); itr != kBtSnoopLogFilterState.end(); itr++) {
612     if (filter_name == itr->first) {
613       return itr->second == true;
614     }
615   }
616   for (auto itr = kBtSnoopLogFilterMode.begin(); itr != kBtSnoopLogFilterMode.end(); itr++) {
617     if (filter_name == itr->first) {
618       return itr->second != SnoopLogger::kBtSnoopLogFilterProfileModeDisabled;
619     }
620   }
621   return false;
622 }
623 
ShouldFilterLog(bool is_received,uint8_t * packet)624 bool SnoopLogger::ShouldFilterLog(bool is_received, uint8_t* packet) {
625   uint16_t conn_handle =
626       ((((uint16_t)packet[ACL_CHANNEL_OFFSET + 1]) << 8) + packet[ACL_CHANNEL_OFFSET]) & 0x0fff;
627   std::lock_guard<std::mutex> lock(filter_tracker_list_mutex);
628   auto& filters = filter_tracker_list[conn_handle];
629   uint16_t cid = (packet[L2CAP_CHANNEL_OFFSET + 1] << 8) + packet[L2CAP_CHANNEL_OFFSET];
630   if (filters.IsRfcommChannel(is_received, cid)) {
631     uint8_t rfcomm_event = packet[RFCOMM_EVENT_OFFSET] & 0b11101111;
632     if (rfcomm_event == RFCOMM_SABME || rfcomm_event == RFCOMM_UA) {
633       return false;
634     }
635 
636     uint8_t rfcomm_dlci = packet[RFCOMM_CHANNEL_OFFSET] >> 2;
637     if (!filters.IsAcceptlistedDlci(rfcomm_dlci)) {
638       return true;
639     }
640   } else if (!filters.IsAcceptlistedL2cap(is_received, cid)) {
641     return true;
642   }
643 
644   return false;
645 }
646 
CalculateAclPacketLength(uint32_t & length,uint8_t * packet,bool)647 void SnoopLogger::CalculateAclPacketLength(
648     uint32_t& length, uint8_t* packet, bool /* is_received */) {
649   uint32_t def_len =
650       ((((uint16_t)packet[ACL_LENGTH_OFFSET + 1]) << 8) + packet[ACL_LENGTH_OFFSET]) +
651       ACL_HEADER_LENGTH + PACKET_TYPE_LENGTH;
652   constexpr uint16_t L2CAP_SIGNALING_CID = 0x0001;
653 
654   if (length == 0) {
655     return;
656   }
657 
658   uint16_t handle =
659       ((((uint16_t)packet[ACL_CHANNEL_OFFSET + 1]) << 8) + packet[ACL_CHANNEL_OFFSET]);
660   uint8_t boundary_flag = GetBoundaryFlag(handle);
661   handle = handle & HANDLE_MASK;
662 
663   if (boundary_flag == START_PACKET_BOUNDARY) {
664     uint16_t l2cap_cid = packet[L2CAP_CHANNEL_OFFSET] | (packet[L2CAP_CHANNEL_OFFSET + 1] << 8);
665     if (l2cap_cid == L2CAP_SIGNALING_CID || handle == kQualcommDebugLogHandle) {
666       length = def_len;
667     } else {
668       if (def_len < MAX_HCI_ACL_LEN) {
669         length = def_len;
670       } else {
671         // Otherwise, return as much as we reasonably can
672         length = MAX_HCI_ACL_LEN;
673       }
674     }
675   }
676 }
677 
PayloadStrip(profile_type_t current_profile,uint8_t * packet,uint32_t hdr_len,uint32_t pl_len)678 uint32_t SnoopLogger::PayloadStrip(
679     profile_type_t current_profile, uint8_t* packet, uint32_t hdr_len, uint32_t pl_len) {
680   uint32_t len = 0;
681   std::string profile_filter_mode = "";
682   log::debug(
683       "current_profile={}, hdr len={}, total len={}",
684       ProfilesFilter::ProfileToString(current_profile),
685       hdr_len,
686       pl_len);
687   std::lock_guard<std::mutex> lock(snoop_log_filters_mutex);
688   switch (current_profile) {
689     case FILTER_PROFILE_PBAP:
690     case FILTER_PROFILE_HFP_HF:
691     case FILTER_PROFILE_HFP_HS:
692       profile_filter_mode =
693           kBtSnoopLogFilterMode[SnoopLogger::kBtSnoopLogFilterProfilePbapModeProperty];
694       break;
695     case FILTER_PROFILE_MAP:
696       profile_filter_mode =
697           kBtSnoopLogFilterMode[SnoopLogger::kBtSnoopLogFilterProfileMapModeProperty];
698       break;
699     default:
700       profile_filter_mode = kBtSnoopLogFilterProfileModeDisabled;
701   }
702 
703   if (profile_filter_mode == SnoopLogger::kBtSnoopLogFilterProfileModeFullfillter) {
704     return 0;
705   } else if (profile_filter_mode == SnoopLogger::kBtSnoopLogFilterProfileModeHeader) {
706     len = hdr_len;
707 
708     packet[ACL_LENGTH_OFFSET] = static_cast<uint8_t>(hdr_len - BASIC_L2CAP_HEADER_LENGTH);
709     packet[ACL_LENGTH_OFFSET + 1] =
710         static_cast<uint8_t>((hdr_len - BASIC_L2CAP_HEADER_LENGTH) >> 8);
711 
712     packet[L2CAP_PDU_LENGTH_OFFSET] =
713         static_cast<uint8_t>(hdr_len - (ACL_HEADER_LENGTH + BASIC_L2CAP_HEADER_LENGTH));
714     packet[L2CAP_PDU_LENGTH_OFFSET + 1] =
715         static_cast<uint8_t>((hdr_len - (ACL_HEADER_LENGTH + BASIC_L2CAP_HEADER_LENGTH)) >> 8);
716 
717   } else if (profile_filter_mode == SnoopLogger::kBtSnoopLogFilterProfileModeMagic) {
718     strcpy(reinterpret_cast<char*>(&packet[hdr_len]), payload_fill_magic);
719 
720     packet[ACL_LENGTH_OFFSET] =
721         static_cast<uint8_t>(hdr_len + magic_pat_len - BASIC_L2CAP_HEADER_LENGTH);
722     packet[ACL_LENGTH_OFFSET + 1] =
723         static_cast<uint8_t>((hdr_len + magic_pat_len - BASIC_L2CAP_HEADER_LENGTH) >> 8);
724 
725     packet[L2CAP_PDU_LENGTH_OFFSET] = static_cast<uint8_t>(
726         hdr_len + magic_pat_len - (ACL_HEADER_LENGTH + BASIC_L2CAP_HEADER_LENGTH));
727     packet[L2CAP_PDU_LENGTH_OFFSET + 1] = static_cast<uint8_t>(
728         (hdr_len + magic_pat_len - (ACL_HEADER_LENGTH + BASIC_L2CAP_HEADER_LENGTH)) >> 8);
729 
730     len = hdr_len + magic_pat_len;
731   } else {
732     // Return unchanged
733     len = hdr_len + pl_len;
734   }
735   return len + PACKET_TYPE_LENGTH;  // including packet type byte
736 }
737 
FilterProfilesHandleHfp(uint8_t * packet,uint32_t length,uint32_t totlen,uint32_t offset)738 uint32_t SnoopLogger::FilterProfilesHandleHfp(
739     uint8_t* packet, uint32_t length, uint32_t totlen, uint32_t offset) {
740   if ((totlen - offset) > cpbr_pat_len) {
741     if (memcmp(&packet[offset], cpbr_pattern, cpbr_pat_len) == 0) {
742       length = offset + cpbr_pat_len + 1;
743       packet[L2CAP_PDU_LENGTH_OFFSET] = offset + cpbr_pat_len - BASIC_L2CAP_HEADER_LENGTH;
744       packet[L2CAP_PDU_LENGTH_OFFSET] =
745           offset + cpbr_pat_len - (ACL_HEADER_LENGTH + BASIC_L2CAP_HEADER_LENGTH);
746       return length;
747     }
748 
749     if (memcmp(&packet[offset], clcc_pattern, clcc_pat_len) == 0) {
750       length = offset + cpbr_pat_len + 1;
751       packet[L2CAP_PDU_LENGTH_OFFSET] = offset + clcc_pat_len - BASIC_L2CAP_HEADER_LENGTH;
752       packet[L2CAP_PDU_LENGTH_OFFSET] =
753           offset + clcc_pat_len - (ACL_HEADER_LENGTH + BASIC_L2CAP_HEADER_LENGTH);
754     }
755   }
756 
757   return length;
758 }
759 
FilterProfilesRfcommChannel(uint8_t * packet,uint8_t & current_offset,uint32_t & length,profile_type_t & current_profile,bluetooth::hal::ProfilesFilter & filters,bool is_received,uint16_t l2cap_channel,uint32_t & offset,uint32_t total_length)760 void SnoopLogger::FilterProfilesRfcommChannel(
761     uint8_t* packet,
762     uint8_t& current_offset,
763     uint32_t& length,
764     profile_type_t& current_profile,
765     bluetooth::hal::ProfilesFilter& filters,
766     bool is_received,
767     uint16_t l2cap_channel,
768     uint32_t& offset,
769     uint32_t total_length) {
770   uint8_t addr, ctrl, pf;
771 
772   addr = packet[current_offset];
773   current_offset += 1;
774   ctrl = packet[RFCOMM_EVENT_OFFSET];
775   current_offset += 1;
776 
777   pf = ctrl & 0x10;
778   ctrl = ctrl & 0xef;
779   addr >>= 2;
780   if (ctrl != RFCOMM_UIH) {
781     return;
782   }
783   current_profile = filters.DlciToProfile(is_received, l2cap_channel, addr);
784   if (current_profile != FILTER_PROFILE_NONE) {
785     uint16_t len;
786     uint8_t ea;
787 
788     len = packet[current_offset];
789     current_offset += 1;
790     ea = len & 1;
791 
792     if (!ea) {
793       current_offset += 1;
794     }
795 
796     if (filters.IsRfcommFlowExt(is_received, l2cap_channel, addr) && pf) {
797       current_offset += 1;  // credit byte
798     }
799     offset = current_offset;
800 
801     if ((filters).IsHfpProfile(is_received, l2cap_channel, addr)) {
802       length = FilterProfilesHandleHfp(packet, length, total_length, offset);
803     } else {
804       length = PayloadStrip(current_profile, packet, offset, total_length - offset);
805     }
806   }
807 }
808 
FilterProfiles(bool is_received,uint8_t * packet)809 uint32_t SnoopLogger::FilterProfiles(bool is_received, uint8_t* packet) {
810   bool frag;
811   uint16_t handle, l2c_chan, l2c_ctl;
812   uint32_t length, totlen, offset;
813   uint8_t current_offset = 0;
814   profile_type_t current_profile = FILTER_PROFILE_NONE;
815   constexpr uint16_t L2CAP_SIGNALING_CID = 0x0001;
816 
817   std::lock_guard<std::mutex> lock(profiles_filter_mutex);
818 
819   handle = ((((uint16_t)packet[ACL_CHANNEL_OFFSET + 1]) << 8) + packet[ACL_CHANNEL_OFFSET]);
820   frag = (GetBoundaryFlag(handle) == CONTINUATION_PACKET_BOUNDARY);
821 
822   handle = handle & HANDLE_MASK;
823   current_offset += 2;
824 
825   length = (((uint16_t)packet[ACL_LENGTH_OFFSET + 1]) << 8) + packet[ACL_LENGTH_OFFSET];
826   current_offset += 2;
827   totlen = length + ACL_HEADER_LENGTH;
828   length += PACKET_TYPE_LENGTH + ACL_HEADER_LENGTH;  // Additional byte is added for packet type
829 
830   l2c_chan = ((uint16_t)packet[L2CAP_CHANNEL_OFFSET + 1] << 8) + packet[L2CAP_CHANNEL_OFFSET];
831   current_offset += 4;
832 
833   auto& filters = profiles_filter_table[handle];
834   if (frag) {
835     l2c_chan = filters.ch_last;
836   } else {
837     filters.ch_last = l2c_chan;
838   }
839 
840   if (l2c_chan != L2CAP_SIGNALING_CID && handle != kQualcommDebugLogHandle) {
841     if (filters.IsL2capFlowExt(is_received, l2c_chan)) {
842       l2c_ctl = ((uint16_t)packet[L2CAP_CONTROL_OFFSET + 1] << 8) + packet[L2CAP_CONTROL_OFFSET];
843       if (!(l2c_ctl & 1)) {                     // I-Frame
844         if (((l2c_ctl >> 14) & 0x3) == 0x01) {  // Start of L2CAP SDU
845           current_offset += 2;
846         }
847       }
848     }
849     offset = current_offset;
850     current_profile = filters.CidToProfile(is_received, l2c_chan);
851     if (current_profile != FILTER_PROFILE_NONE) {
852       if (frag) {
853         return PACKET_TYPE_LENGTH + ACL_HEADER_LENGTH;
854       }
855       return PayloadStrip(current_profile, packet, offset, totlen - offset);
856     }
857 
858     if (filters.IsRfcommChannel(is_received, l2c_chan)) {
859       FilterProfilesRfcommChannel(
860           packet,
861           current_offset,
862           length,
863           current_profile,
864           filters,
865           is_received,
866           l2c_chan,
867           offset,
868           totlen);
869     }
870   }
871 
872   return length;
873 }
874 
AcceptlistL2capChannel(uint16_t conn_handle,uint16_t local_cid,uint16_t remote_cid)875 void SnoopLogger::AcceptlistL2capChannel(
876     uint16_t conn_handle, uint16_t local_cid, uint16_t remote_cid) {
877   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
878       !IsFilterEnabled(kBtSnoopLogFilterProfileRfcommProperty)) {
879     return;
880   }
881 
882   log::debug(
883       "Acceptlisting l2cap channel: conn_handle={}, local cid={}, remote cid={}",
884       conn_handle,
885       local_cid,
886       remote_cid);
887   std::lock_guard<std::mutex> lock(filter_tracker_list_mutex);
888 
889   // This will create the entry if there is no associated filter with the
890   // connection.
891   filter_tracker_list[conn_handle].AddL2capCid(local_cid, remote_cid);
892 }
893 
AcceptlistRfcommDlci(uint16_t conn_handle,uint16_t local_cid,uint8_t dlci)894 void SnoopLogger::AcceptlistRfcommDlci(uint16_t conn_handle, uint16_t local_cid, uint8_t dlci) {
895   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
896       !IsFilterEnabled(kBtSnoopLogFilterProfileRfcommProperty)) {
897     return;
898   }
899 
900   log::debug("Acceptlisting rfcomm channel: local cid={}, dlci={}", local_cid, dlci);
901   std::lock_guard<std::mutex> lock(filter_tracker_list_mutex);
902 
903   filter_tracker_list[conn_handle].AddRfcommDlci(dlci);
904 }
905 
AddRfcommL2capChannel(uint16_t conn_handle,uint16_t local_cid,uint16_t remote_cid)906 void SnoopLogger::AddRfcommL2capChannel(
907     uint16_t conn_handle, uint16_t local_cid, uint16_t remote_cid) {
908   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
909       !IsFilterEnabled(kBtSnoopLogFilterProfileRfcommProperty)) {
910     return;
911   }
912 
913   log::debug(
914       "Rfcomm data going over l2cap channel: conn_handle={} local cid={} remote cid={}",
915       conn_handle,
916       local_cid,
917       remote_cid);
918   std::lock_guard<std::mutex> lock(filter_tracker_list_mutex);
919 
920   filter_tracker_list[conn_handle].SetRfcommCid(local_cid, remote_cid);
921   local_cid_to_acl.insert({local_cid, conn_handle});
922 }
923 
ClearL2capAcceptlist(uint16_t conn_handle,uint16_t local_cid,uint16_t remote_cid)924 void SnoopLogger::ClearL2capAcceptlist(
925     uint16_t conn_handle, uint16_t local_cid, uint16_t remote_cid) {
926   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
927       !IsFilterEnabled(kBtSnoopLogFilterProfileRfcommProperty)) {
928     return;
929   }
930 
931   log::debug(
932       "Clearing acceptlist from l2cap channel. conn_handle={} local cid={} remote cid={}",
933       conn_handle,
934       local_cid,
935       remote_cid);
936   std::lock_guard<std::mutex> lock(filter_tracker_list_mutex);
937 
938   filter_tracker_list[conn_handle].RemoveL2capCid(local_cid, remote_cid);
939 }
940 
IsA2dpMediaChannel(uint16_t conn_handle,uint16_t cid,bool is_local_cid)941 bool SnoopLogger::IsA2dpMediaChannel(uint16_t conn_handle, uint16_t cid, bool is_local_cid) {
942   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
943       !IsFilterEnabled(kBtSnoopLogFilterProfileA2dpProperty)) {
944     return false;
945   }
946 
947   std::lock_guard<std::mutex> lock(a2dpMediaChannels_mutex);
948   auto iter = std::find_if(
949       a2dpMediaChannels.begin(),
950       a2dpMediaChannels.end(),
951       [conn_handle, cid, is_local_cid](auto& el) {
952         if (el.conn_handle != conn_handle) return false;
953 
954         if (is_local_cid) return el.local_cid == cid;
955 
956         return el.remote_cid == cid;
957       });
958 
959   return iter != a2dpMediaChannels.end();
960 }
961 
IsA2dpMediaPacket(bool is_received,uint8_t * packet)962 bool SnoopLogger::IsA2dpMediaPacket(bool is_received, uint8_t* packet) {
963   uint16_t cid, conn_handle;
964   bool is_local_cid = is_received;
965   /*is_received signifies Rx packet so packet will have local_cid at offset 6
966    * Tx packet with is_received as false and have remote_cid at the offset*/
967 
968   conn_handle = (uint16_t)((packet[0] + (packet[1] << 8)) & 0x0FFF);
969   cid = (uint16_t)(packet[6] + (packet[7] << 8));
970 
971   return IsA2dpMediaChannel(conn_handle, cid, is_local_cid);
972 }
973 
AddA2dpMediaChannel(uint16_t conn_handle,uint16_t local_cid,uint16_t remote_cid)974 void SnoopLogger::AddA2dpMediaChannel(
975     uint16_t conn_handle, uint16_t local_cid, uint16_t remote_cid) {
976   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
977       !IsFilterEnabled(kBtSnoopLogFilterProfileA2dpProperty)) {
978     return;
979   }
980 
981   if (!SnoopLogger::IsA2dpMediaChannel(conn_handle, local_cid, true)) {
982     log::info(
983         "Add A2DP media channel filtering. conn_handle={} local cid={} remote cid={}",
984         conn_handle,
985         local_cid,
986         remote_cid);
987     std::lock_guard<std::mutex> lock(a2dpMediaChannels_mutex);
988     a2dpMediaChannels.push_back({conn_handle, local_cid, remote_cid});
989   }
990 }
991 
RemoveA2dpMediaChannel(uint16_t conn_handle,uint16_t local_cid)992 void SnoopLogger::RemoveA2dpMediaChannel(uint16_t conn_handle, uint16_t local_cid) {
993   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
994       !IsFilterEnabled(kBtSnoopLogFilterProfileA2dpProperty)) {
995     return;
996   }
997 
998   std::lock_guard<std::mutex> lock(a2dpMediaChannels_mutex);
999   a2dpMediaChannels.erase(
1000       std::remove_if(
1001           a2dpMediaChannels.begin(),
1002           a2dpMediaChannels.end(),
1003           [conn_handle, local_cid](auto& el) {
1004             return (el.conn_handle == conn_handle && el.local_cid == local_cid);
1005           }),
1006       a2dpMediaChannels.end());
1007 }
1008 
SetRfcommPortOpen(uint16_t conn_handle,uint16_t local_cid,uint8_t dlci,uint16_t uuid,bool flow)1009 void SnoopLogger::SetRfcommPortOpen(
1010     uint16_t conn_handle, uint16_t local_cid, uint8_t dlci, uint16_t uuid, bool flow) {
1011   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
1012       (!IsFilterEnabled(kBtSnoopLogFilterProfilePbapModeProperty) &&
1013        !IsFilterEnabled(kBtSnoopLogFilterProfileMapModeProperty))) {
1014     return;
1015   }
1016 
1017   std::lock_guard<std::mutex> lock(profiles_filter_mutex);
1018 
1019   profile_type_t profile = FILTER_PROFILE_NONE;
1020   auto& filters = profiles_filter_table[conn_handle];
1021   {
1022     filters.SetupProfilesFilter(
1023         IsFilterEnabled(kBtSnoopLogFilterProfilePbapModeProperty),
1024         IsFilterEnabled(kBtSnoopLogFilterProfileMapModeProperty));
1025   }
1026 
1027   log::info(
1028       "RFCOMM port is opened: handle={}(0x{:x}), lcid={}(0x{:x}), dlci={}(0x{:x}), "
1029       "uuid={}(0x{:x}){}",
1030       conn_handle,
1031       conn_handle,
1032       local_cid,
1033       local_cid,
1034       dlci,
1035       dlci,
1036       uuid,
1037       uuid,
1038       flow ? " Credit Based Flow Control enabled" : "");
1039 
1040   if (uuid == PROFILE_UUID_PBAP || (dlci >> 1) == PROFILE_SCN_PBAP) {
1041     profile = FILTER_PROFILE_PBAP;
1042   } else if (uuid == PROFILE_UUID_MAP || (dlci >> 1) == PROFILE_SCN_MAP) {
1043     profile = FILTER_PROFILE_MAP;
1044   } else if (uuid == PROFILE_UUID_HFP_HS) {
1045     profile = FILTER_PROFILE_HFP_HS;
1046   } else if (uuid == PROFILE_UUID_HFP_HF) {
1047     profile = FILTER_PROFILE_HFP_HF;
1048   }
1049 
1050   if (profile >= 0) {
1051     filters.ProfileRfcommOpen(profile, local_cid, dlci, uuid, flow);
1052   }
1053 }
1054 
SetRfcommPortClose(uint16_t handle,uint16_t local_cid,uint8_t dlci,uint16_t uuid)1055 void SnoopLogger::SetRfcommPortClose(
1056     uint16_t handle, uint16_t local_cid, uint8_t dlci, uint16_t uuid) {
1057   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
1058       (!IsFilterEnabled(kBtSnoopLogFilterProfilePbapModeProperty) &&
1059        !IsFilterEnabled(kBtSnoopLogFilterProfileMapModeProperty))) {
1060     return;
1061   }
1062 
1063   std::lock_guard<std::mutex> lock(profiles_filter_mutex);
1064 
1065   auto& filters = profiles_filter_table[handle];
1066   log::info(
1067       "RFCOMM port is closed: handle={}(0x{:x}), lcid={}(0x{:x}), dlci={}(0x{:x}), uuid={}(0x{:x})",
1068       handle,
1069       handle,
1070       local_cid,
1071       local_cid,
1072       dlci,
1073       dlci,
1074       uuid,
1075       uuid);
1076 
1077   filters.ProfileRfcommClose(filters.DlciToProfile(true, local_cid, dlci));
1078 }
1079 
SetL2capChannelOpen(uint16_t handle,uint16_t local_cid,uint16_t remote_cid,uint16_t psm,bool flow)1080 void SnoopLogger::SetL2capChannelOpen(
1081     uint16_t handle, uint16_t local_cid, uint16_t remote_cid, uint16_t psm, bool flow) {
1082   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
1083       (!IsFilterEnabled(kBtSnoopLogFilterProfilePbapModeProperty) &&
1084        !IsFilterEnabled(kBtSnoopLogFilterProfileMapModeProperty))) {
1085     return;
1086   }
1087 
1088   std::lock_guard<std::mutex> lock(profiles_filter_mutex);
1089   profile_type_t profile = FILTER_PROFILE_NONE;
1090   auto& filters = profiles_filter_table[handle];
1091   {
1092     filters.SetupProfilesFilter(
1093         IsFilterEnabled(kBtSnoopLogFilterProfilePbapModeProperty),
1094         IsFilterEnabled(kBtSnoopLogFilterProfileMapModeProperty));
1095   }
1096 
1097   log::info(
1098       "L2CAP channel is opened: handle={}(0x{:x}), lcid={}(0x{:x}), rcid={}(0x{:x}), psm=0x{:x}{}",
1099       handle,
1100       handle,
1101       local_cid,
1102       local_cid,
1103       remote_cid,
1104       remote_cid,
1105       psm,
1106       flow ? " Standard or Enhanced Control enabled" : "");
1107 
1108   if (psm == PROFILE_PSM_RFCOMM) {
1109     filters.ch_rfc_l = local_cid;
1110     filters.ch_rfc_r = remote_cid;
1111   } else if (psm == PROFILE_PSM_PBAP) {
1112     profile = FILTER_PROFILE_PBAP;
1113   } else if (psm == PROFILE_PSM_MAP) {
1114     profile = FILTER_PROFILE_MAP;
1115   }
1116 
1117   if (profile >= 0) {
1118     filters.ProfileL2capOpen(profile, local_cid, remote_cid, psm, flow);
1119   }
1120 }
1121 
SetL2capChannelClose(uint16_t handle,uint16_t local_cid,uint16_t remote_cid)1122 void SnoopLogger::SetL2capChannelClose(uint16_t handle, uint16_t local_cid, uint16_t remote_cid) {
1123   if (btsnoop_mode_ != kBtSnoopLogModeFiltered ||
1124       (!IsFilterEnabled(kBtSnoopLogFilterProfilePbapModeProperty) &&
1125        !IsFilterEnabled(kBtSnoopLogFilterProfileMapModeProperty))) {
1126     return;
1127   }
1128 
1129   std::lock_guard<std::mutex> lock(profiles_filter_mutex);
1130 
1131   auto& filters = profiles_filter_table[handle];
1132 
1133   log::info(
1134       "L2CAP channel is closed: handle={}(0x{:x}), lcid={}(0x{:x}), rcid={}(0x{:x})",
1135       handle,
1136       handle,
1137       local_cid,
1138       local_cid,
1139       remote_cid,
1140       remote_cid);
1141 
1142   filters.ProfileL2capClose(filters.CidToProfile(true, local_cid));
1143 }
1144 
FilterCapturedPacket(HciPacket & packet,Direction direction,PacketType type,uint32_t & length,PacketHeaderType header)1145 void SnoopLogger::FilterCapturedPacket(
1146     HciPacket& packet,
1147     Direction direction,
1148     PacketType type,
1149     uint32_t& length,
1150     PacketHeaderType header) {
1151   if (btsnoop_mode_ != kBtSnoopLogModeFiltered || type != PacketType::ACL) {
1152     return;
1153   }
1154 
1155   if (IsFilterEnabled(kBtSnoopLogFilterProfileA2dpProperty)) {
1156     if (IsA2dpMediaPacket(direction == Direction::INCOMING, (uint8_t*)packet.data())) {
1157       length = 0;
1158       return;
1159     }
1160   }
1161 
1162   if (IsFilterEnabled(kBtSnoopLogFilterHeadersProperty)) {
1163     CalculateAclPacketLength(length, (uint8_t*)packet.data(), direction == Direction::INCOMING);
1164   }
1165 
1166   if (IsFilterEnabled(kBtSnoopLogFilterProfilePbapModeProperty) ||
1167       IsFilterEnabled(kBtSnoopLogFilterProfileMapModeProperty)) {
1168     // If HeadersFiltered applied, do not use ProfilesFiltered
1169     if (length == ntohl(header.length_original)) {
1170       if (packet.size() + EXTRA_BUF_SIZE > DEFAULT_PACKET_SIZE) {
1171         // Add additional bytes for magic string in case
1172         // payload length is less than the length of magic string.
1173         packet.resize((size_t)(packet.size() + EXTRA_BUF_SIZE));
1174       }
1175 
1176       length = FilterProfiles(direction == Direction::INCOMING, (uint8_t*)packet.data());
1177       if (length == 0) return;
1178     }
1179   }
1180 
1181   if (IsFilterEnabled(kBtSnoopLogFilterProfileRfcommProperty)) {
1182     bool shouldFilter =
1183         SnoopLogger::ShouldFilterLog(direction == Direction::INCOMING, (uint8_t*)packet.data());
1184     if (shouldFilter) {
1185       length = L2CAP_HEADER_SIZE + PACKET_TYPE_LENGTH;
1186     }
1187   }
1188 }
1189 
Capture(const HciPacket & immutable_packet,Direction direction,PacketType type)1190 void SnoopLogger::Capture(const HciPacket& immutable_packet, Direction direction, PacketType type) {
1191   //// TODO(b/335520123) update FilterCapture to stop modifying packets ////
1192   HciPacket mutable_packet(immutable_packet);
1193   HciPacket& packet = mutable_packet;
1194   //////////////////////////////////////////////////////////////////////////
1195   uint64_t timestamp_us =
1196       std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::system_clock::now().time_since_epoch())
1197           .count();
1198   std::bitset<32> flags = 0;
1199   switch (type) {
1200     case PacketType::CMD:
1201       flags.set(0, false);
1202       flags.set(1, true);
1203       break;
1204     case PacketType::ACL:
1205     case PacketType::ISO:
1206     case PacketType::SCO:
1207       flags.set(0, direction == Direction::INCOMING);
1208       flags.set(1, false);
1209       break;
1210     case PacketType::EVT:
1211       flags.set(0, true);
1212       flags.set(1, true);
1213       break;
1214   }
1215   uint32_t length = packet.size() + /* type byte */ PACKET_TYPE_LENGTH;
1216   PacketHeaderType header = {.length_original = htonl(length),
1217                              .length_captured = htonl(length),
1218                              .flags = htonl(static_cast<uint32_t>(flags.to_ulong())),
1219                              .dropped_packets = 0,
1220                              .timestamp = htonll(timestamp_us + kBtSnoopEpochDelta),
1221                              .type = static_cast<uint8_t>(type)};
1222   {
1223     std::lock_guard<std::recursive_mutex> lock(file_mutex_);
1224     if (btsnoop_mode_ == kBtSnoopLogModeDisabled) {
1225       // btsnoop disabled, log in-memory btsnooz log only
1226       std::stringstream ss;
1227       size_t included_length = get_btsnooz_packet_length_to_write(packet, type, qualcomm_debug_log_enabled_);
1228       header.length_captured = htonl(included_length + /* type byte */ PACKET_TYPE_LENGTH);
1229       if (!ss.write(reinterpret_cast<const char*>(&header), sizeof(PacketHeaderType))) {
1230         log::error("Failed to write packet header for btsnooz, error: \"{}\"", strerror(errno));
1231       }
1232       if (!ss.write(reinterpret_cast<const char*>(packet.data()), included_length)) {
1233         log::error("Failed to write packet payload for btsnooz, error: \"{}\"", strerror(errno));
1234       }
1235       btsnooz_buffer_.Push(ss.str());
1236       return;
1237     }
1238 
1239     FilterCapturedPacket(packet, direction, type, length, header);
1240 
1241     if (length == 0) {
1242       return;
1243     } else if (length != ntohl(header.length_original)) {
1244       header.length_captured = htonl(length);
1245     }
1246 
1247     packet_counter_++;
1248     if (packet_counter_ > max_packets_per_file_) {
1249       OpenNextSnoopLogFile();
1250     }
1251     if (!btsnoop_ostream_.write(reinterpret_cast<const char*>(&header), sizeof(PacketHeaderType))) {
1252       log::error("Failed to write packet header for btsnoop, error: \"{}\"", strerror(errno));
1253     }
1254     if (!btsnoop_ostream_.write(reinterpret_cast<const char*>(packet.data()), length - 1)) {
1255       log::error("Failed to write packet payload for btsnoop, error: \"{}\"", strerror(errno));
1256     }
1257 
1258     if (socket_ != nullptr) {
1259       socket_->Write(&header, sizeof(PacketHeaderType));
1260       socket_->Write(packet.data(), (size_t)(length - 1));
1261     }
1262 
1263     // std::ofstream::flush() pushes user data into kernel memory. The data will be written even if this process
1264     // crashes. However, data will be lost if there is a kernel panic, which is out of scope of BT snoop log.
1265     // NOTE: std::ofstream::write() followed by std::ofstream::flush() has similar effect as UNIX write(fd, data, len)
1266     //       as write() syscall dumps data into kernel memory directly
1267     if (!btsnoop_ostream_.flush()) {
1268       log::error("Failed to flush, error: \"{}\"", strerror(errno));
1269     }
1270   }
1271 }
1272 
DumpSnoozLogToFile(const std::vector<std::string> & data) const1273 void SnoopLogger::DumpSnoozLogToFile(const std::vector<std::string>& data) const {
1274   std::lock_guard<std::recursive_mutex> lock(file_mutex_);
1275   if (btsnoop_mode_ != kBtSnoopLogModeDisabled) {
1276     log::debug("btsnoop log is enabled, skip dumping btsnooz log");
1277     return;
1278   }
1279 
1280   log::debug("Dumping btsnooz log data to {}", snooz_log_path_);
1281   auto last_file_path = get_last_log_path(snooz_log_path_);
1282 
1283   if (os::FileExists(snooz_log_path_)) {
1284     if (!os::RenameFile(snooz_log_path_, last_file_path)) {
1285       log::error(
1286           "Unabled to rename existing snooz log from \"{}\" to \"{}\"",
1287           snooz_log_path_,
1288           last_file_path);
1289     }
1290   } else {
1291     log::info("Previous log file \"{}\" does not exist, skip renaming", snooz_log_path_);
1292   }
1293 
1294   mode_t prevmask = umask(0);
1295   // do not use std::ios::app as we want override the existing file
1296   std::ofstream btsnooz_ostream(snooz_log_path_, std::ios::binary | std::ios::out);
1297   if (!btsnooz_ostream.good()) {
1298     log::fatal(
1299         "Unable to open snoop log at \"{}\", error: \"{}\"", snooz_log_path_, strerror(errno));
1300   }
1301   umask(prevmask);
1302   if (!btsnooz_ostream.write(
1303           reinterpret_cast<const char*>(&SnoopLoggerCommon::kBtSnoopFileHeader),
1304           sizeof(SnoopLoggerCommon::FileHeaderType))) {
1305     log::fatal(
1306         "Unable to write file header to \"{}\", error: \"{}\"", snooz_log_path_, strerror(errno));
1307   }
1308   for (const auto& packet : data) {
1309     if (!btsnooz_ostream.write(packet.data(), packet.size())) {
1310       log::error("Failed to write packet payload for btsnooz, error: \"{}\"", strerror(errno));
1311     }
1312   }
1313   if (!btsnooz_ostream.flush()) {
1314     log::error("Failed to flush, error: \"{}\"", strerror(errno));
1315   }
1316 }
1317 
ListDependencies(ModuleList *) const1318 void SnoopLogger::ListDependencies(ModuleList* /* list */) const {
1319   // We have no dependencies
1320 }
1321 
Start()1322 void SnoopLogger::Start() {
1323   std::lock_guard<std::recursive_mutex> lock(file_mutex_);
1324   if (btsnoop_mode_ != kBtSnoopLogModeDisabled) {
1325     OpenNextSnoopLogFile();
1326 
1327     if (btsnoop_mode_ == kBtSnoopLogModeFiltered) {
1328       EnableFilters();
1329     }
1330 
1331     auto snoop_logger_socket = std::make_unique<SnoopLoggerSocket>(&syscall_if);
1332     snoop_logger_socket_thread_ =
1333         std::make_unique<SnoopLoggerSocketThread>(std::move(snoop_logger_socket));
1334     auto thread_started_future = snoop_logger_socket_thread_->Start();
1335     thread_started_future.wait();
1336     if (thread_started_future.get()) {
1337       RegisterSocket(snoop_logger_socket_thread_.get());
1338     } else {
1339       snoop_logger_socket_thread_->Stop();
1340       snoop_logger_socket_thread_.reset();
1341       snoop_logger_socket_thread_ = nullptr;
1342     }
1343   }
1344   alarm_ = std::make_unique<os::RepeatingAlarm>(GetHandler());
1345   alarm_->Schedule(
1346       common::Bind(&delete_old_btsnooz_files, snooz_log_path_, snooz_log_life_time_), snooz_log_delete_alarm_interval_);
1347 }
1348 
Stop()1349 void SnoopLogger::Stop() {
1350   std::lock_guard<std::recursive_mutex> lock(file_mutex_);
1351   log::debug("Closing btsnoop log data at {}", snoop_log_path_);
1352   CloseCurrentSnoopLogFile();
1353 
1354   if (snoop_logger_socket_thread_ != nullptr) {
1355     snoop_logger_socket_thread_->Stop();
1356     snoop_logger_socket_thread_.reset();
1357     snoop_logger_socket_thread_ = nullptr;
1358     socket_ = nullptr;
1359   }
1360 
1361   btsnoop_mode_.clear();
1362   // Disable all filters
1363   DisableFilters();
1364 
1365   // Cancel the alarm
1366   alarm_->Cancel();
1367   alarm_.reset();
1368   // delete any existing snooz logs
1369   if (!snoop_log_persists) {
1370     delete_btsnoop_files(snooz_log_path_);
1371   }
1372 }
1373 
GetDumpsysData(flatbuffers::FlatBufferBuilder *) const1374 DumpsysDataFinisher SnoopLogger::GetDumpsysData(
1375     flatbuffers::FlatBufferBuilder* /* builder */) const {
1376   DumpSnoozLogToFile(btsnooz_buffer_.Pull());
1377   return EmptyDumpsysDataFinisher;
1378 }
1379 
GetMaxPacketsPerFile()1380 size_t SnoopLogger::GetMaxPacketsPerFile() {
1381   // Allow override max packet per file via system property
1382   auto max_packets_per_file = kDefaultBtSnoopMaxPacketsPerFile;
1383   {
1384     auto max_packets_per_file_prop = os::GetSystemProperty(kBtSnoopMaxPacketsPerFileProperty);
1385     if (max_packets_per_file_prop) {
1386       auto max_packets_per_file_number = common::Uint64FromString(max_packets_per_file_prop.value());
1387       if (max_packets_per_file_number) {
1388         max_packets_per_file = max_packets_per_file_number.value();
1389       }
1390     }
1391   }
1392   return max_packets_per_file;
1393 }
1394 
GetMaxPacketsPerBuffer()1395 size_t SnoopLogger::GetMaxPacketsPerBuffer() {
1396   // We want to use at most 256 KB memory for btsnooz log for release builds
1397   // and 512 KB memory for userdebug/eng builds
1398   auto is_debuggable = os::GetSystemPropertyBool(kIsDebuggableProperty, false);
1399 
1400   size_t btsnooz_max_memory_usage_bytes = (is_debuggable ? 1024 : 256) * 1024;
1401   // Calculate max number of packets based on max memory usage and max packet size
1402   return btsnooz_max_memory_usage_bytes / kDefaultBtSnoozMaxBytesPerPacket;
1403 }
1404 
GetBtSnoopMode()1405 std::string SnoopLogger::GetBtSnoopMode() {
1406   // Default mode is FILTERED on userdebug/eng build, DISABLED on user build.
1407   // In userdebug/eng build, it can also be overwritten by modifying the global setting
1408   std::string default_mode = kBtSnoopLogModeDisabled;
1409   {
1410     auto is_debuggable = os::GetSystemPropertyBool(kIsDebuggableProperty, false);
1411     if (is_debuggable) {
1412       auto default_mode_property = os::GetSystemProperty(kBtSnoopDefaultLogModeProperty);
1413       if (default_mode_property) {
1414         default_mode = std::move(default_mode_property.value());
1415       } else {
1416         default_mode = kBtSnoopLogModeFiltered;
1417       }
1418     }
1419   }
1420 
1421   // Get the actual mode if exist
1422   std::string btsnoop_mode = default_mode;
1423   {
1424     auto btsnoop_mode_prop = os::GetSystemProperty(kBtSnoopLogModeProperty);
1425     if (btsnoop_mode_prop) {
1426       btsnoop_mode = std::move(btsnoop_mode_prop.value());
1427     }
1428   }
1429 
1430   // If Snoop Logger already set up, return current mode
1431   bool btsnoop_mode_empty = btsnoop_mode_.empty();
1432   log::info("btsnoop_mode_empty: {}", btsnoop_mode_empty);
1433   if (!btsnoop_mode_empty) {
1434     return btsnoop_mode_;
1435   }
1436 
1437   return btsnoop_mode;
1438 }
1439 
RegisterSocket(SnoopLoggerSocketInterface * socket)1440 void SnoopLogger::RegisterSocket(SnoopLoggerSocketInterface* socket) {
1441   std::lock_guard<std::recursive_mutex> lock(file_mutex_);
1442   socket_ = socket;
1443 }
1444 
IsBtSnoopLogPersisted()1445 bool SnoopLogger::IsBtSnoopLogPersisted() {
1446   auto is_debuggable = os::GetSystemPropertyBool(kIsDebuggableProperty, false);
1447   return is_debuggable && os::GetSystemPropertyBool(kBtSnoopLogPersists, false);
1448 }
1449 
IsQualcommDebugLogEnabled()1450 bool SnoopLogger::IsQualcommDebugLogEnabled() {
1451   // Check system prop if the soc manufacturer is Qualcomm
1452   bool qualcomm_debug_log_enabled = false;
1453   {
1454     auto soc_manufacturer_prop = os::GetSystemProperty(kSoCManufacturerProperty);
1455     qualcomm_debug_log_enabled = soc_manufacturer_prop.has_value() &&
1456                                  common::StringTrim(soc_manufacturer_prop.value()) == kSoCManufacturerQualcomm;
1457   }
1458   return qualcomm_debug_log_enabled;
1459 }
1460 
__anon184083ae0502() 1461 const ModuleFactory SnoopLogger::Factory = ModuleFactory([]() {
1462   return new SnoopLogger(
1463       os::ParameterProvider::SnoopLogFilePath(),
1464       os::ParameterProvider::SnoozLogFilePath(),
1465       GetMaxPacketsPerFile(),
1466       GetMaxPacketsPerBuffer(),
1467       GetBtSnoopMode(),
1468       IsQualcommDebugLogEnabled(),
1469       kBtSnoozLogLifeTime,
1470       kBtSnoozLogDeleteRepeatingAlarmInterval,
1471       IsBtSnoopLogPersisted());
1472 });
1473 
1474 }  // namespace hal
1475 }  // namespace bluetooth
1476