From c86135ad0cd8457868a0ad2732ebdd67d2215bf3 Mon Sep 17 00:00:00 2001 From: Jack He Date: Wed, 17 Feb 2021 23:52:51 -0800 Subject: [PATCH] [GD ACL] Add btsnooz support in GD * Support in-memory btsnooz log in GD * It uses maximum of 256KB of memory to store HCI commands, events, L2CAP signaling channel data, and first 14 bytes of other ACL packet * The data is dumped to a log file when dumpsys is taken for the Bluetooth module and when Bluetooth stack shutsdown so that developer can debug Bluetooth issues with it Bug: 180569201 Test: gd/cert/run Test: bluetooth_test_gd Tag: #gd-refactor Change-Id: Ib334609b0f6667846f458d2967ffa520d3af39e3 --- gd/cert/devices_config.json | 2 + gd/cert/gd_device.py | 11 +- gd/facade/facade_main.cc | 5 + gd/hal/snoop_logger.cc | 205 ++++++++++++++++++++++++++++++------ gd/hal/snoop_logger.h | 15 ++- gd/hal/snoop_logger_test.cc | 130 +++++++++++++++++++++-- gd/os/android/parameter_provider.cc | 17 +++ gd/os/host/parameter_provider.cc | 24 ++++- gd/os/parameter_provider.h | 5 + 9 files changed, 366 insertions(+), 48 deletions(-) diff --git a/gd/cert/devices_config.json b/gd/cert/devices_config.json index dde211ec3..8bd257a19 100644 --- a/gd/cert/devices_config.json +++ b/gd/cert/devices_config.json @@ -23,6 +23,7 @@ "--grpc-port=$(grpc_port)", "--root-server-port=$(grpc_root_server_port)", "--btsnoop=/data/misc/bluetooth/logs/btsnoop_hci.log", + "--btsnooz=/data/misc/bluetooth/logs/btsnooz_hci.log", "--btconfig=/data/misc/bluedroid/bt_config.conf", "--signal-port=$(signal_port)" ] @@ -44,6 +45,7 @@ "--grpc-port=$(grpc_port)", "--root-server-port=$(grpc_root_server_port)", "--btsnoop=/data/misc/bluetooth/logs/btsnoop_hci.log", + "--btsnooz=/data/misc/bluetooth/logs/btsnooz_hci.log", "--btconfig=/data/misc/bluedroid/bt_config.conf", "--signal-port=$(signal_port)" ] diff --git a/gd/cert/gd_device.py b/gd/cert/gd_device.py index 1e813e79a..15f383ff4 100644 --- a/gd/cert/gd_device.py +++ b/gd/cert/gd_device.py @@ -169,6 +169,8 @@ class GdDeviceBase(ABC): '%s_%s_backing_logs.txt' % (self.type_identifier, self.label)) if "--btsnoop=" not in " ".join(cmd): cmd.append("--btsnoop=%s" % os.path.join(self.log_path_base, '%s_btsnoop_hci.log' % self.label)) + if "--btsnooz=" not in " ".join(cmd): + cmd.append("--btsnooz=%s" % os.path.join(self.log_path_base, '%s_btsnooz_hci.log' % self.label)) if "--btconfig=" not in " ".join(cmd): cmd.append("--btconfig=%s" % os.path.join(self.log_path_base, '%s_bt_config.conf' % self.label)) self.cmd = cmd @@ -425,14 +427,19 @@ class GdAndroidDevice(GdDeviceBase): logging.error("Error during setup: " + str(error)) try: + self.adb.shell("rm /data/misc/bluetooth/logs/btsnooz_hci.log") + except AdbCommandError as error: + logging.error("Error during setup: " + str(error)) + + try: self.adb.shell("rm /data/misc/bluedroid/bt_config.conf") except AdbCommandError as error: - logging.error("Error during cleanup: " + str(error)) + logging.error("Error during setup: " + str(error)) try: self.adb.shell("rm /data/misc/bluedroid/bt_config.bak") except AdbCommandError as error: - logging.error("Error during cleanup: " + str(error)) + logging.error("Error during setup: " + str(error)) self.ensure_no_output(self.adb.shell("svc bluetooth disable")) diff --git a/gd/facade/facade_main.cc b/gd/facade/facade_main.cc index 0bba72760..f3d11c2db 100644 --- a/gd/facade/facade_main.cc +++ b/gd/facade/facade_main.cc @@ -109,6 +109,7 @@ int main(int argc, const char** argv) { const std::string arg_rootcanal_port = "--rootcanal-port="; const std::string arg_signal_port = "--signal-port="; const std::string arg_btsnoop_path = "--btsnoop="; + const std::string arg_btsnooz_path = "--btsnooz="; const std::string arg_btconfig_path = "--btconfig="; for (int i = 1; i < argc; i++) { std::string arg = argv[i]; @@ -130,6 +131,10 @@ int main(int argc, const char** argv) { CHECK(::bluetooth::os::SetSystemProperty( ::bluetooth::hal::SnoopLogger::kBtSnoopLogModeProperty, ::bluetooth::hal::SnoopLogger::kBtSnoopLogModeFull)); } + if (arg.find(arg_btsnooz_path) == 0) { + auto btsnooz_path = arg.substr(arg_btsnooz_path.size()); + ::bluetooth::os::ParameterProvider::OverrideSnoozLogFilePath(btsnooz_path); + } if (arg.find(arg_btconfig_path) == 0) { auto btconfig_path = arg.substr(arg_btconfig_path.size()); ::bluetooth::os::ParameterProvider::OverrideConfigFilePath(btconfig_path); diff --git a/gd/hal/snoop_logger.cc b/gd/hal/snoop_logger.cc index cd8a0b1b2..5acbbb0c4 100644 --- a/gd/hal/snoop_logger.cc +++ b/gd/hal/snoop_logger.cc @@ -19,9 +19,12 @@ #include #include +#include #include #include +#include +#include "common/circular_buffer.h" #include "common/strings.h" #include "os/files.h" #include "os/log.h" @@ -63,36 +66,96 @@ constexpr SnoopLogger::FileHeaderType kBtSnoopFileHeader = { // the relevant system property constexpr size_t kDefaultBtSnoopMaxPacketsPerFile = 0xffff; -std::string get_btsnoop_log_path(std::string btsnoop_path, bool filtered) { +// We want to use at most 256 KB memory for btsnooz log +constexpr size_t kDefaultBtsnoozMaxMemoryUsageBytes = 256 * 1024; +// We restrict the maximum packet size to 150 bytes +constexpr size_t kDefaultBtSnoozMaxBytesPerPacket = 150; +constexpr size_t kDefaultBtSnoozMaxPayloadBytesPerPacket = + kDefaultBtSnoozMaxBytesPerPacket - sizeof(SnoopLogger::PacketHeaderType); +// Calculate max number of packets based on max memory usage and max packet size +constexpr size_t kDefaultBtSnoozMaxPacketsPerBuffer = + kDefaultBtsnoozMaxMemoryUsageBytes / kDefaultBtSnoozMaxBytesPerPacket; + +std::string get_btsnoop_log_path(std::string log_dir, bool filtered) { if (filtered) { - return btsnoop_path.append(".filtered"); + log_dir.append(".filtered"); } - return btsnoop_path; + return log_dir; } -std::string get_btsnoop_last_log_path(std::string btsnoop_path) { - return btsnoop_path.append(".last"); +std::string get_last_log_path(std::string log_file_path) { + return log_file_path.append(".last"); } void delete_btsnoop_files(const std::string& log_path) { - LOG_INFO("Deleting snoop logs if they exist"); + LOG_INFO("Deleting logs if they exist"); if (os::FileExists(log_path)) { if (!os::RemoveFile(log_path)) { - LOG_ERROR("Failed to remove main snoop log faile at \"%s\"", log_path.c_str()); + LOG_ERROR("Failed to remove main log file at \"%s\"", log_path.c_str()); } } else { - LOG_INFO("Main snoop log file does not exist at \"%s\"", log_path.c_str()); + LOG_INFO("Main log file does not exist at \"%s\"", log_path.c_str()); } - auto last_log_path = get_btsnoop_last_log_path(log_path); + auto last_log_path = get_last_log_path(log_path); if (os::FileExists(last_log_path)) { if (!os::RemoveFile(last_log_path)) { - LOG_ERROR("Failed to remove last snoop log faile at \"%s\"", log_path.c_str()); + LOG_ERROR("Failed to remove last log file at \"%s\"", log_path.c_str()); } } else { - LOG_INFO("Last snoop log file does not exist at \"%s\"", log_path.c_str()); + LOG_INFO("Last log file does not exist at \"%s\"", log_path.c_str()); } } +size_t get_btsnooz_packet_length_to_write(const HciPacket& packet, SnoopLogger::PacketType type) { + static const size_t kAclHeaderSize = 4; + static const size_t kL2capHeaderSize = 4; + static const size_t kL2capCidOffset = (kAclHeaderSize + 2); + static const uint16_t kL2capSignalingCid = 0x0001; + + // Maximum amount of ACL data to log. + // Enough for an RFCOMM frame up to the frame check; + // not enough for a HID report or audio data. + static const size_t kMaxBtsnoozAclSize = 14; + + // Calculate packet length to be included + size_t included_length = 0; + switch (type) { + case SnoopLogger::PacketType::CMD: + case SnoopLogger::PacketType::EVT: + included_length = packet.size(); + break; + + case SnoopLogger::PacketType::ACL: { + // Log ACL and L2CAP header by default + size_t len_hci_acl = kAclHeaderSize + kL2capHeaderSize; + // Check if we have enough data for an L2CAP header + if (packet.size() > len_hci_acl) { + uint16_t l2cap_cid = + static_cast(packet[kL2capCidOffset]) | + static_cast((static_cast(packet[kL2capCidOffset + 1]) << static_cast(8))); + if (l2cap_cid == kL2capSignalingCid) { + // For the signaling CID, take the full packet. + // That way, the PSM setup is captured, allowing decoding of PSMs down + // the road. + return packet.size(); + } else { + // Otherwise, return as much as we reasonably can + len_hci_acl = kMaxBtsnoozAclSize; + } + } + included_length = std::min(len_hci_acl, packet.size()); + break; + } + + case SnoopLogger::PacketType::ISO: + case SnoopLogger::PacketType::SCO: + default: + // We are not logging SCO and ISO packets in snooz log as they may contain voice data + break; + } + return std::min(included_length, kDefaultBtSnoozMaxPayloadBytesPerPacket); +} + } // namespace const std::string SnoopLogger::kBtSnoopLogModeDisabled = "disabled"; @@ -104,31 +167,42 @@ const std::string SnoopLogger::kIsDebuggableProperty = "ro.debuggable"; const std::string SnoopLogger::kBtSnoopLogModeProperty = "persist.bluetooth.btsnooplogmode"; const std::string SnoopLogger::kBtSnoopDefaultLogModeProperty = "persist.bluetooth.btsnoopdefaultmode"; -SnoopLogger::SnoopLogger(std::string log_path, size_t max_packets_per_file, const std::string& btsnoop_mode) - : file_path_(std::move(log_path)), max_packets_per_file_(max_packets_per_file) { +SnoopLogger::SnoopLogger( + std::string snoop_log_path, + std::string snooz_log_path, + size_t max_packets_per_file, + const std::string& btsnoop_mode) + : snoop_log_path_(std::move(snoop_log_path)), + snooz_log_path_(std::move(snooz_log_path)), + max_packets_per_file_(max_packets_per_file), + btsnooz_buffer_(kDefaultBtSnoozMaxPacketsPerBuffer) { if (false && btsnoop_mode == kBtSnoopLogModeFiltered) { // TODO(b/163733538): implement filtered snoop log in GD, currently filtered == disabled LOG_INFO("Filtered Snoop Logs enabled"); is_enabled_ = true; is_filtered_ = true; // delete unfiltered logs - delete_btsnoop_files(get_btsnoop_log_path(file_path_, false)); + delete_btsnoop_files(get_btsnoop_log_path(snoop_log_path_, false)); + // delete snooz logs + delete_btsnoop_files(snooz_log_path_); } else if (btsnoop_mode == kBtSnoopLogModeFull) { LOG_INFO("Snoop Logs fully enabled"); is_enabled_ = true; is_filtered_ = false; // delete filtered logs - delete_btsnoop_files(get_btsnoop_log_path(file_path_, true)); + delete_btsnoop_files(get_btsnoop_log_path(snoop_log_path_, true)); + // delete snooz logs + delete_btsnoop_files(snooz_log_path_); } else { LOG_INFO("Snoop Logs disabled"); is_enabled_ = false; is_filtered_ = false; // delete both filtered and unfiltered logs - delete_btsnoop_files(get_btsnoop_log_path(file_path_, true)); - delete_btsnoop_files(get_btsnoop_log_path(file_path_, false)); + delete_btsnoop_files(get_btsnoop_log_path(snoop_log_path_, true)); + delete_btsnoop_files(get_btsnoop_log_path(snoop_log_path_, false)); } // Add ".filtered" extension if necessary - file_path_ = get_btsnoop_log_path(file_path_, is_filtered_); + snoop_log_path_ = get_btsnoop_log_path(snoop_log_path_, is_filtered_); } void SnoopLogger::CloseCurrentSnoopLogFile() { @@ -144,26 +218,28 @@ void SnoopLogger::OpenNextSnoopLogFile() { std::lock_guard lock(file_mutex_); CloseCurrentSnoopLogFile(); - auto last_file_path = get_btsnoop_last_log_path(file_path_); + auto last_file_path = get_last_log_path(snoop_log_path_); - if (os::FileExists(file_path_)) { - if (!os::RenameFile(file_path_, last_file_path)) { + if (os::FileExists(snoop_log_path_)) { + if (!os::RenameFile(snoop_log_path_, last_file_path)) { LOG_ERROR( - "Unabled to rename existing snoop log from \"%s\" to \"%s\"", file_path_.c_str(), last_file_path.c_str()); + "Unabled to rename existing snoop log from \"%s\" to \"%s\"", + snoop_log_path_.c_str(), + last_file_path.c_str()); } } else { - LOG_INFO("Previous log file \"%s\" does not exist, skip renaming", file_path_.c_str()); + LOG_INFO("Previous log file \"%s\" does not exist, skip renaming", snoop_log_path_.c_str()); } mode_t prevmask = umask(0); // do not use std::ios::app as we want override the existing file - btsnoop_ostream_.open(file_path_, std::ios::binary | std::ios::out); + btsnoop_ostream_.open(snoop_log_path_, std::ios::binary | std::ios::out); if (!btsnoop_ostream_.good()) { - LOG_ALWAYS_FATAL("Unable to open snoop log at \"%s\", error: \"%s\"", file_path_.c_str(), strerror(errno)); + LOG_ALWAYS_FATAL("Unable to open snoop log at \"%s\", error: \"%s\"", snoop_log_path_.c_str(), strerror(errno)); } umask(prevmask); if (!btsnoop_ostream_.write(reinterpret_cast(&kBtSnoopFileHeader), sizeof(FileHeaderType))) { - LOG_ALWAYS_FATAL("Unable to write file header to \"%s\", error: \"%s\"", file_path_.c_str(), strerror(errno)); + LOG_ALWAYS_FATAL("Unable to write file header to \"%s\", error: \"%s\"", snoop_log_path_.c_str(), strerror(errno)); } if (!btsnoop_ostream_.flush()) { LOG_ERROR("Failed to flush, error: \"%s\"", strerror(errno)); @@ -171,10 +247,6 @@ void SnoopLogger::OpenNextSnoopLogFile() { } void SnoopLogger::Capture(const HciPacket& packet, Direction direction, PacketType type) { - if (!is_enabled_) { - // btsnoop disabled - return; - } uint64_t timestamp_us = std::chrono::duration_cast(std::chrono::system_clock::now().time_since_epoch()) .count(); @@ -207,15 +279,29 @@ void SnoopLogger::Capture(const HciPacket& packet, Direction direction, PacketTy .type = static_cast(type)}; { std::lock_guard lock(file_mutex_); + if (!is_enabled_) { + // btsnoop disabled, log in-memory btsnooz log only + std::stringstream ss; + size_t included_length = get_btsnooz_packet_length_to_write(packet, type); + header.length_captured = htonl(included_length + /* type byte */ 1); + if (!ss.write(reinterpret_cast(&header), sizeof(PacketHeaderType))) { + LOG_ERROR("Failed to write packet header for btsnooz, error: \"%s\"", strerror(errno)); + } + if (!ss.write(reinterpret_cast(packet.data()), included_length)) { + LOG_ERROR("Failed to write packet payload for btsnooz, error: \"%s\"", strerror(errno)); + } + btsnooz_buffer_.Push(ss.str()); + return; + } packet_counter_++; if (packet_counter_ > max_packets_per_file_) { OpenNextSnoopLogFile(); } if (!btsnoop_ostream_.write(reinterpret_cast(&header), sizeof(PacketHeaderType))) { - LOG_ERROR("Failed to write packet header, error: \"%s\"", strerror(errno)); + LOG_ERROR("Failed to write packet header for btsnoop, error: \"%s\"", strerror(errno)); } if (!btsnoop_ostream_.write(reinterpret_cast(packet.data()), packet.size())) { - LOG_ERROR("Failed to write packet payload, error: \"%s\"", strerror(errno)); + LOG_ERROR("Failed to write packet payload for btsnoop, error: \"%s\"", strerror(errno)); } // std::ofstream::flush() pushes user data into kernel memory. The data will be written even if this process // crashes. However, data will be lost if there is a kernel panic, which is out of scope of BT snoop log. @@ -227,6 +313,46 @@ void SnoopLogger::Capture(const HciPacket& packet, Direction direction, PacketTy } } +void SnoopLogger::DumpSnoozLogToFile(const std::vector& data) const { + std::lock_guard lock(file_mutex_); + if (is_enabled_) { + LOG_DEBUG("btsnoop log is enabled, skip dumping btsnooz log"); + return; + } + + auto last_file_path = get_last_log_path(snooz_log_path_); + + if (os::FileExists(snooz_log_path_)) { + if (!os::RenameFile(snooz_log_path_, last_file_path)) { + LOG_ERROR( + "Unabled to rename existing snooz log from \"%s\" to \"%s\"", + snooz_log_path_.c_str(), + last_file_path.c_str()); + } + } else { + LOG_INFO("Previous log file \"%s\" does not exist, skip renaming", snooz_log_path_.c_str()); + } + + mode_t prevmask = umask(0); + // do not use std::ios::app as we want override the existing file + std::ofstream btsnooz_ostream(snooz_log_path_, std::ios::binary | std::ios::out); + if (!btsnooz_ostream.good()) { + LOG_ALWAYS_FATAL("Unable to open snoop log at \"%s\", error: \"%s\"", snooz_log_path_.c_str(), strerror(errno)); + } + umask(prevmask); + if (!btsnooz_ostream.write(reinterpret_cast(&kBtSnoopFileHeader), sizeof(FileHeaderType))) { + LOG_ALWAYS_FATAL("Unable to write file header to \"%s\", error: \"%s\"", snooz_log_path_.c_str(), strerror(errno)); + } + for (const auto& packet : data) { + if (!btsnooz_ostream.write(packet.data(), packet.size())) { + LOG_ERROR("Failed to write packet payload for btsnooz, error: \"%s\"", strerror(errno)); + } + } + if (!btsnooz_ostream.flush()) { + LOG_ERROR("Failed to flush, error: \"%s\"", strerror(errno)); + } +} + void SnoopLogger::ListDependencies(ModuleList* list) { // We have no dependencies } @@ -240,9 +366,18 @@ void SnoopLogger::Start() { void SnoopLogger::Stop() { std::lock_guard lock(file_mutex_); + LOG_DEBUG("Dumping btsnooz log data to %s", snooz_log_path_.c_str()); + DumpSnoozLogToFile(btsnooz_buffer_.Drain()); + LOG_DEBUG("Closing btsnoop log data at %s", snoop_log_path_.c_str()); CloseCurrentSnoopLogFile(); } +DumpsysDataFinisher SnoopLogger::GetDumpsysData(flatbuffers::FlatBufferBuilder* builder) const { + LOG_DEBUG("Dumping btsnooz log data to %s", snooz_log_path_.c_str()); + DumpSnoozLogToFile(btsnooz_buffer_.Pull()); + return Module::GetDumpsysData(builder); +} + size_t SnoopLogger::GetMaxPacketsPerFile() { // Allow override max packet per file via system property auto max_packets_per_file = kDefaultBtSnoopMaxPacketsPerFile; @@ -284,7 +419,11 @@ std::string SnoopLogger::GetBtSnoopMode() { } const ModuleFactory SnoopLogger::Factory = ModuleFactory([]() { - return new SnoopLogger(os::ParameterProvider::SnoopLogFilePath(), GetMaxPacketsPerFile(), GetBtSnoopMode()); + return new SnoopLogger( + os::ParameterProvider::SnoopLogFilePath(), + os::ParameterProvider::SnoozLogFilePath(), + GetMaxPacketsPerFile(), + GetBtSnoopMode()); }); } // namespace hal diff --git a/gd/hal/snoop_logger.h b/gd/hal/snoop_logger.h index 7e1852048..b83484a3a 100644 --- a/gd/hal/snoop_logger.h +++ b/gd/hal/snoop_logger.h @@ -21,6 +21,7 @@ #include #include +#include "common/circular_buffer.h" #include "hal/hci_hal.h" #include "module.h" @@ -85,20 +86,28 @@ class SnoopLogger : public ::bluetooth::Module { void ListDependencies(ModuleList* list) override; void Start() override; void Stop() override; + DumpsysDataFinisher GetDumpsysData(flatbuffers::FlatBufferBuilder* builder) const override; // Visible for testing - SnoopLogger(std::string log_path, size_t max_packets_per_file, const std::string& btsnoop_mode); + SnoopLogger( + std::string snoop_log_path, + std::string snooz_log_path, + size_t max_packets_per_file, + const std::string& btsnoop_mode); void CloseCurrentSnoopLogFile(); void OpenNextSnoopLogFile(); + void DumpSnoozLogToFile(const std::vector& data) const; private: - std::string file_path_; + std::string snoop_log_path_; + std::string snooz_log_path_; std::ofstream btsnoop_ostream_; bool is_enabled_ = false; bool is_filtered_ = false; size_t max_packets_per_file_; + common::CircularBuffer btsnooz_buffer_; size_t packet_counter_ = 0; - std::recursive_mutex file_mutex_; + mutable std::recursive_mutex file_mutex_; }; } // namespace hal diff --git a/gd/hal/snoop_logger_test.cc b/gd/hal/snoop_logger_test.cc index ffc48f66d..fbb1fbae0 100644 --- a/gd/hal/snoop_logger_test.cc +++ b/gd/hal/snoop_logger_test.cc @@ -38,7 +38,16 @@ std::vector kInformationRequest = { 0x02, 0x00, }; -} + +std::vector kSdpConnectionRequest = { + 0x08, 0x20, 0x0c, 0x00, 0x08, 0x00, 0x01, 0x00, 0x02, 0x0c, 0x04, 0x00, 0x01, 0x00, 0x44, 0x00}; + +std::vector kAvdtpSuspend = {0x02, 0x02, 0x00, 0x07, 0x00, 0x03, 0x00, 0x8d, 0x00, 0x90, 0x09, 0x04}; + +std::vector kHfpAtNrec0 = {0x02, 0x02, 0x20, 0x13, 0x00, 0x0f, 0x00, 0x41, 0x00, 0x09, 0xff, 0x15, + 0x01, 0x41, 0x54, 0x2b, 0x4e, 0x52, 0x45, 0x43, 0x3d, 0x30, 0x0d, 0x5c}; + +} // namespace using bluetooth::TestModuleRegistry; using bluetooth::hal::SnoopLogger; @@ -46,8 +55,12 @@ using bluetooth::hal::SnoopLogger; // Expose protected constructor for test class TestSnoopLoggerModule : public SnoopLogger { public: - TestSnoopLoggerModule(std::string log_path, size_t max_packets_per_file, const std::string& btsnoop_mode) - : SnoopLogger(std::move(log_path), max_packets_per_file, btsnoop_mode) {} + TestSnoopLoggerModule( + std::string snoop_log_path, + std::string snooz_log_path, + size_t max_packets_per_file, + const std::string& btsnoop_mode) + : SnoopLogger(std::move(snoop_log_path), std::move(snooz_log_path), max_packets_per_file, btsnoop_mode) {} }; class SnoopLoggerModuleTest : public Test { @@ -56,9 +69,13 @@ class SnoopLoggerModuleTest : public Test { temp_dir_ = std::filesystem::temp_directory_path(); temp_snoop_log_ = temp_dir_ / "btsnoop_hci.log"; temp_snoop_log_last_ = temp_dir_ / "btsnoop_hci.log.last"; + temp_snooz_log_ = temp_dir_ / "btsnooz_hci.log"; + temp_snooz_log_last_ = temp_dir_ / "btsnooz_hci.log.last"; DeleteSnoopLogFiles(); ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_)); ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_last_)); + ASSERT_FALSE(std::filesystem::exists(temp_snooz_log_)); + ASSERT_FALSE(std::filesystem::exists(temp_snooz_log_last_)); } void TearDown() override { @@ -72,16 +89,25 @@ class SnoopLoggerModuleTest : public Test { if (std::filesystem::exists(temp_snoop_log_last_)) { ASSERT_TRUE(std::filesystem::remove(temp_snoop_log_last_)); } + if (std::filesystem::exists(temp_snooz_log_)) { + ASSERT_TRUE(std::filesystem::remove(temp_snooz_log_)); + } + if (std::filesystem::exists(temp_snooz_log_last_)) { + ASSERT_TRUE(std::filesystem::remove(temp_snooz_log_last_)); + } } std::filesystem::path temp_dir_; std::filesystem::path temp_snoop_log_; std::filesystem::path temp_snoop_log_last_; + std::filesystem::path temp_snooz_log_; + std::filesystem::path temp_snooz_log_last_; }; TEST_F(SnoopLoggerModuleTest, empty_snoop_log_test) { // Actual test - auto* snoop_looger = new TestSnoopLoggerModule(temp_snoop_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); TestModuleRegistry test_registry; test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); test_registry.StopAll(); @@ -94,7 +120,8 @@ TEST_F(SnoopLoggerModuleTest, empty_snoop_log_test) { TEST_F(SnoopLoggerModuleTest, disable_snoop_log_test) { // Actual test - auto* snoop_looger = new TestSnoopLoggerModule(temp_snoop_log_.string(), 10, SnoopLogger::kBtSnoopLogModeDisabled); + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeDisabled); TestModuleRegistry test_registry; test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); test_registry.StopAll(); @@ -102,11 +129,13 @@ TEST_F(SnoopLoggerModuleTest, disable_snoop_log_test) { // Verify states after test ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_)); ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_last_)); + ASSERT_TRUE(std::filesystem::exists(temp_snooz_log_)); } TEST_F(SnoopLoggerModuleTest, capture_one_packet_test) { // Actual test - auto* snoop_looger = new TestSnoopLoggerModule(temp_snoop_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); TestModuleRegistry test_registry; test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); @@ -122,10 +151,91 @@ TEST_F(SnoopLoggerModuleTest, capture_one_packet_test) { sizeof(SnoopLogger::FileHeaderType) + sizeof(SnoopLogger::PacketHeaderType) + kInformationRequest.size()); } +TEST_F(SnoopLoggerModuleTest, capture_hci_cmd_btsnooz_test) { + // Actual test + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeDisabled); + TestModuleRegistry test_registry; + test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); + + snoop_looger->Capture(kInformationRequest, SnoopLogger::Direction::OUTGOING, SnoopLogger::PacketType::CMD); + + test_registry.StopAll(); + + // Verify states after test + ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_)); + ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_last_)); + ASSERT_TRUE(std::filesystem::exists(temp_snooz_log_)); + ASSERT_EQ( + std::filesystem::file_size(temp_snooz_log_), + sizeof(SnoopLogger::FileHeaderType) + sizeof(SnoopLogger::PacketHeaderType) + kInformationRequest.size()); +} + +TEST_F(SnoopLoggerModuleTest, capture_l2cap_signal_packet_btsnooz_test) { + // Actual test + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeDisabled); + TestModuleRegistry test_registry; + test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); + + snoop_looger->Capture(kSdpConnectionRequest, SnoopLogger::Direction::OUTGOING, SnoopLogger::PacketType::ACL); + + test_registry.StopAll(); + + // Verify states after test + ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_)); + ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_last_)); + ASSERT_TRUE(std::filesystem::exists(temp_snooz_log_)); + ASSERT_EQ( + std::filesystem::file_size(temp_snooz_log_), + sizeof(SnoopLogger::FileHeaderType) + sizeof(SnoopLogger::PacketHeaderType) + kSdpConnectionRequest.size()); +} + +TEST_F(SnoopLoggerModuleTest, capture_l2cap_short_data_packet_btsnooz_test) { + // Actual test + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeDisabled); + TestModuleRegistry test_registry; + test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); + + snoop_looger->Capture(kAvdtpSuspend, SnoopLogger::Direction::OUTGOING, SnoopLogger::PacketType::ACL); + + test_registry.StopAll(); + + // Verify states after test + ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_)); + ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_last_)); + ASSERT_TRUE(std::filesystem::exists(temp_snooz_log_)); + ASSERT_EQ( + std::filesystem::file_size(temp_snooz_log_), + sizeof(SnoopLogger::FileHeaderType) + sizeof(SnoopLogger::PacketHeaderType) + kAvdtpSuspend.size()); +} + +TEST_F(SnoopLoggerModuleTest, capture_l2cap_long_data_packet_btsnooz_test) { + // Actual test + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeDisabled); + TestModuleRegistry test_registry; + test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); + + snoop_looger->Capture(kHfpAtNrec0, SnoopLogger::Direction::OUTGOING, SnoopLogger::PacketType::ACL); + + test_registry.StopAll(); + + // Verify states after test + ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_)); + ASSERT_FALSE(std::filesystem::exists(temp_snoop_log_last_)); + ASSERT_TRUE(std::filesystem::exists(temp_snooz_log_)); + ASSERT_EQ( + std::filesystem::file_size(temp_snooz_log_), + sizeof(SnoopLogger::FileHeaderType) + sizeof(SnoopLogger::PacketHeaderType) + 14); +} + TEST_F(SnoopLoggerModuleTest, rotate_file_at_new_session_test) { // Start once { - auto* snoop_looger = new TestSnoopLoggerModule(temp_snoop_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); TestModuleRegistry test_registry; test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); snoop_looger->Capture(kInformationRequest, SnoopLogger::Direction::OUTGOING, SnoopLogger::PacketType::CMD); @@ -141,7 +251,8 @@ TEST_F(SnoopLoggerModuleTest, rotate_file_at_new_session_test) { // Start again { - auto* snoop_looger = new TestSnoopLoggerModule(temp_snoop_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); TestModuleRegistry test_registry; test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); snoop_looger->Capture(kInformationRequest, SnoopLogger::Direction::OUTGOING, SnoopLogger::PacketType::CMD); @@ -162,7 +273,8 @@ TEST_F(SnoopLoggerModuleTest, rotate_file_at_new_session_test) { TEST_F(SnoopLoggerModuleTest, rotate_file_after_full_test) { // Actual test - auto* snoop_looger = new TestSnoopLoggerModule(temp_snoop_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); + auto* snoop_looger = new TestSnoopLoggerModule( + temp_snoop_log_.string(), temp_snooz_log_.string(), 10, SnoopLogger::kBtSnoopLogModeFull); TestModuleRegistry test_registry; test_registry.InjectTestModule(&SnoopLogger::Factory, snoop_looger); diff --git a/gd/os/android/parameter_provider.cc b/gd/os/android/parameter_provider.cc index c87d8e0d7..dcf7c407e 100644 --- a/gd/os/android/parameter_provider.cc +++ b/gd/os/android/parameter_provider.cc @@ -26,6 +26,7 @@ namespace { std::mutex parameter_mutex; std::string config_file_path; std::string snoop_log_file_path; +std::string snooz_log_file_path; } // namespace // On Android we always write a single default location @@ -59,5 +60,21 @@ void ParameterProvider::OverrideSnoopLogFilePath(const std::string& path) { snoop_log_file_path = path; } +// Return the path to the default snooz log file location +std::string ParameterProvider::SnoozLogFilePath() { + { + std::lock_guard lock(parameter_mutex); + if (!snooz_log_file_path.empty()) { + return snooz_log_file_path; + } + } + return "/data/misc/bluetooth/logs/btsnooz_hci.log"; +} + +void ParameterProvider::OverrideSnoozLogFilePath(const std::string& path) { + std::lock_guard lock(parameter_mutex); + snooz_log_file_path = path; +} + } // namespace os } // namespace bluetooth \ No newline at end of file diff --git a/gd/os/host/parameter_provider.cc b/gd/os/host/parameter_provider.cc index 2d99c90f3..2220f940e 100644 --- a/gd/os/host/parameter_provider.cc +++ b/gd/os/host/parameter_provider.cc @@ -31,6 +31,7 @@ namespace { std::mutex parameter_mutex; std::string config_file_path; std::string snoop_log_file_path; +std::string snooz_log_file_path; } // namespace // Write to $PWD/bt_stack.conf if $PWD can be found, otherwise, write to $HOME/bt_stack.conf @@ -64,7 +65,7 @@ std::string ParameterProvider::SnoopLogFilePath() { char cwd[PATH_MAX] = {}; if (getcwd(cwd, sizeof(cwd)) == nullptr) { LOG_ERROR("Failed to get current working directory due to \"%s\", returning default", strerror(errno)); - return "bt_config.conf"; + return "btsnoop_hci.log"; } return std::string(cwd) + "/btsnoop_hci.log"; } @@ -74,5 +75,26 @@ void ParameterProvider::OverrideSnoopLogFilePath(const std::string& path) { snoop_log_file_path = path; } +// Return the path to the default snooz log file location +std::string ParameterProvider::SnoozLogFilePath() { + { + std::lock_guard lock(parameter_mutex); + if (!snooz_log_file_path.empty()) { + return snooz_log_file_path; + } + } + char cwd[PATH_MAX] = {}; + if (getcwd(cwd, sizeof(cwd)) == nullptr) { + LOG_ERROR("Failed to get current working directory due to \"%s\", returning default", strerror(errno)); + return "bt_config.conf"; + } + return std::string(cwd) + "/btsnooz_hci.log"; +} + +void ParameterProvider::OverrideSnoozLogFilePath(const std::string& path) { + std::lock_guard lock(parameter_mutex); + snooz_log_file_path = path; +} + } // namespace os } // namespace bluetooth \ No newline at end of file diff --git a/gd/os/parameter_provider.h b/gd/os/parameter_provider.h index 6d7bed7b8..72557bbd5 100644 --- a/gd/os/parameter_provider.h +++ b/gd/os/parameter_provider.h @@ -32,6 +32,11 @@ class ParameterProvider { static std::string SnoopLogFilePath(); static void OverrideSnoopLogFilePath(const std::string& path); + + // Return the path to the default snooz log file location + static std::string SnoozLogFilePath(); + + static void OverrideSnoozLogFilePath(const std::string& path); }; } // namespace os -- 2.11.0