diff --git a/proto/bluetooth/metrics/bluetooth.proto b/proto/bluetooth/metrics/bluetooth.proto index 9418762dfbc2bc5d1fa2fd1a4b049a7ad5dba0e5..fecb040e2e4d8cbe7b702912bf2951f53edad1f6 100644 --- a/proto/bluetooth/metrics/bluetooth.proto +++ b/proto/bluetooth/metrics/bluetooth.proto @@ -51,6 +51,12 @@ message BluetoothLog { // Number of ScanEvent including discarded ones beyond capacity optional int64 num_scan_event = 9; + + // Statistics about Bluetooth profile connections + repeated ProfileConnectionStats profile_connection_stats = 10; + + // Statistics about Headset profile connections + repeated HeadsetProfileConnectionStats headset_profile_connection_stats = 11; } // The information about the device. @@ -229,3 +235,52 @@ message ScanEvent { optional int64 event_time_millis = 5; // [(datapol.semantic_type) = ST_TIMESTAMP]; } + +// Profile IDs defined in BluetoothProfile API class +// Values must match API class values +enum ProfileId { + PROFILE_UNKNOWN = 0; + HEADSET = 1; + A2DP = 2; + HEALTH = 3; + HID_HOST = 4; + PAN = 5; + PBAP = 6; + GATT = 7; + GATT_SERVER = 8; + MAP = 9; + SAP = 10; + A2DP_SINK = 11; + AVRCP_CONTROLLER = 12; + AVRCP = 13; + HEADSET_CLIENT = 16; + PBAP_CLIENT = 17; + MAP_CLIENT = 18; + HID_DEVICE = 19; + OPP = 20; + HEARING_AID = 21; +} + +// Statistics about Bluetooth profile connections +message ProfileConnectionStats { + // Profile id defined in BluetoothProfile.java + optional ProfileId profile_id = 1; + + // Number of times that this profile is connected since last metrics dump + optional int32 num_times_connected = 2; +} + +enum HeadsetProfileType { + HEADSET_PROFILE_UNKNOWN = 0; + HSP = 1; + HFP = 2; +} + +// Statistics about headset profile connections +message HeadsetProfileConnectionStats { + // Type of headset profile connected + optional HeadsetProfileType headset_profile_type = 1; + + // Number of times this type of headset profile is connected + optional int32 num_times_connected = 2; +} \ No newline at end of file diff --git a/system/btif/src/bluetooth.cc b/system/btif/src/bluetooth.cc index d10bbd15d320cc5a15aa34dd30d9e36acbf06018..9d52fdddb20b7a703a1ed773eab3acea739c86ad 100644 --- a/system/btif/src/bluetooth.cc +++ b/system/btif/src/bluetooth.cc @@ -328,8 +328,7 @@ static void dump(int fd, const char** arguments) { } static void dumpMetrics(std::string* output) { - system_bt_osi::BluetoothMetricsLogger::GetInstance()->WriteString(output, - true); + system_bt_osi::BluetoothMetricsLogger::GetInstance()->WriteString(output); } static const void* get_profile_interface(const char* profile_id) { diff --git a/system/btif/src/btif_hf.cc b/system/btif/src/btif_hf.cc index 9df2917eb8c1dd06a658140e3761c817e2bf489e..5573160e6b728020a5cb6d155ad14c44fe0c27cd 100644 --- a/system/btif/src/btif_hf.cc +++ b/system/btif/src/btif_hf.cc @@ -31,19 +31,18 @@ #include <cstring> #include <ctime> -#include <bta/include/bta_ag_api.h> #include <hardware/bluetooth.h> #include <hardware/bluetooth_headset_callbacks.h> #include <hardware/bluetooth_headset_interface.h> #include <hardware/bt_hf.h> -#include "bta/include/bta_ag_api.h" #include "bta/include/utl.h" #include "bta_ag_api.h" #include "btif_common.h" #include "btif_hf.h" #include "btif_profile_queue.h" #include "btif_util.h" +#include "osi/include/metrics.h" namespace bluetooth { namespace headset { @@ -320,6 +319,8 @@ static void btif_hf_upstreams_evt(uint16_t event, char* p_param) { btif_hf_cb[idx].state = BTHF_CONNECTION_STATE_CONNECTED; btif_hf_cb[idx].peer_feat = 0; clear_phone_state_multihf(idx); + system_bt_osi::BluetoothMetricsLogger::GetInstance() + ->LogHeadsetProfileRfcConnection(p_data->open.service_id); } else if (btif_hf_cb[idx].state == BTHF_CONNECTION_STATE_CONNECTING) { LOG(ERROR) << __func__ << ": AG open failed for " << btif_hf_cb[idx].connected_bda << ", status " diff --git a/system/osi/include/metrics.h b/system/osi/include/metrics.h index c64fd4a609d88de63c822333bcb056dad5847e74..4f968d2d76fd0d206f91c05a37da49e3d738ec35 100644 --- a/system/osi/include/metrics.h +++ b/system/osi/include/metrics.h @@ -18,6 +18,7 @@ #pragma once +#include <bta/include/bta_api.h> #include <stdint.h> #include <memory> #include <string> @@ -209,13 +210,20 @@ class BluetoothMetricsLogger { */ void LogA2dpSession(const A2dpSessionMetrics& a2dp_session_metrics); + /** + * Log Headset profile RFCOMM connection event + * + * @param service_id the BTA service ID for this headset connection + */ + void LogHeadsetProfileRfcConnection(tBTA_SERVICE_ID service_id); + /* - * Writes the metrics, in base64 protobuf format, into the descriptor FD - * If CLEAR is true, metrics events are cleared afterwards. + * Writes the metrics, in base64 protobuf format, into the descriptor FD, + * metrics events are always cleared after dump */ - void WriteBase64(int fd, bool clear); - void WriteBase64String(std::string* serialized, bool clear); - void WriteString(std::string* serialized, bool clear); + void WriteBase64(int fd); + void WriteBase64String(std::string* serialized); + void WriteString(std::string* serialized); /* * Reset the metrics logger by cleaning up its staging queues and existing diff --git a/system/osi/src/metrics.cc b/system/osi/src/metrics.cc index bfb54ccac4b52c566796040ba3f1e977e2faefe8..96907c0b576433fb4409ba782c9ee194c60d62f0 100644 --- a/system/osi/src/metrics.cc +++ b/system/osi/src/metrics.cc @@ -19,6 +19,7 @@ #include <unistd.h> #include <algorithm> +#include <array> #include <cerrno> #include <chrono> #include <cstdint> @@ -55,7 +56,12 @@ using bluetooth::metrics::BluetoothMetricsProto::ScanEvent_ScanTechnologyType; using bluetooth::metrics::BluetoothMetricsProto::ScanEvent_ScanEventType; using bluetooth::metrics::BluetoothMetricsProto::WakeEvent; using bluetooth::metrics::BluetoothMetricsProto::WakeEvent_WakeEventType; - +using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType; +using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_MIN; +using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_MAX; +using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_ARRAYSIZE; +using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_IsValid; +using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileConnectionStats; /* * Get current OS boot time in millisecond */ @@ -233,6 +239,7 @@ struct BluetoothMetricsLogger::impl { wake_event_queue_(new LeakyBondedQueue<WakeEvent>(max_wake_event)), scan_event_queue_(new LeakyBondedQueue<ScanEvent>(max_scan_event)) { bluetooth_log_ = BluetoothLog::default_instance().New(); + headset_profile_connection_counts_.fill(0); bluetooth_session_ = nullptr; bluetooth_session_start_time_ms_ = 0; a2dp_session_metrics_ = A2dpSessionMetrics(); @@ -240,6 +247,8 @@ struct BluetoothMetricsLogger::impl { /* Bluetooth log lock protected */ BluetoothLog* bluetooth_log_; + std::array<int, HeadsetProfileType_ARRAYSIZE> + headset_profile_connection_counts_; std::recursive_mutex bluetooth_log_lock_; /* End Bluetooth log lock protected */ /* Bluetooth session lock protected */ @@ -397,29 +406,44 @@ void BluetoothMetricsLogger::LogA2dpSession( pimpl_->a2dp_session_metrics_.buffer_underruns_count); } -void BluetoothMetricsLogger::WriteString(std::string* serialized, bool clear) { +void BluetoothMetricsLogger::LogHeadsetProfileRfcConnection( + tBTA_SERVICE_ID service_id) { + std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_); + switch (service_id) { + case BTA_HSP_SERVICE_ID: + pimpl_->headset_profile_connection_counts_[HeadsetProfileType::HSP]++; + break; + case BTA_HFP_SERVICE_ID: + pimpl_->headset_profile_connection_counts_[HeadsetProfileType::HFP]++; + break; + default: + pimpl_->headset_profile_connection_counts_ + [HeadsetProfileType::HEADSET_PROFILE_UNKNOWN]++; + break; + } + return; +} + +void BluetoothMetricsLogger::WriteString(std::string* serialized) { std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_); LOG_DEBUG(LOG_TAG, "%s building metrics", __func__); Build(); LOG_DEBUG(LOG_TAG, "%s serializing metrics", __func__); if (!pimpl_->bluetooth_log_->SerializeToString(serialized)) { LOG_ERROR(LOG_TAG, "%s: error serializing metrics", __func__); - return; - } - if (clear) { - pimpl_->bluetooth_log_->Clear(); } + // Always clean up log objects + pimpl_->bluetooth_log_->Clear(); } -void BluetoothMetricsLogger::WriteBase64String(std::string* serialized, - bool clear) { - this->WriteString(serialized, clear); +void BluetoothMetricsLogger::WriteBase64String(std::string* serialized) { + this->WriteString(serialized); base::Base64Encode(*serialized, serialized); } -void BluetoothMetricsLogger::WriteBase64(int fd, bool clear) { +void BluetoothMetricsLogger::WriteBase64(int fd) { std::string protoBase64; - this->WriteBase64String(&protoBase64, clear); + this->WriteBase64String(&protoBase64); ssize_t ret; OSI_NO_INTR(ret = write(fd, protoBase64.c_str(), protoBase64.size())); if (ret == -1) { @@ -476,6 +500,19 @@ void BluetoothMetricsLogger::Build() { bluetooth_log->mutable_wake_event()->AddAllocated( pimpl_->wake_event_queue_->Dequeue()); } + for (size_t i = 0; i < HeadsetProfileType_ARRAYSIZE; ++i) { + int num_times_connected = pimpl_->headset_profile_connection_counts_[i]; + if (HeadsetProfileType_IsValid(i) && num_times_connected > 0) { + HeadsetProfileConnectionStats* headset_profile_connection_stats = + bluetooth_log->add_headset_profile_connection_stats(); + // Able to static_cast because HeadsetProfileType_IsValid(i) is true + headset_profile_connection_stats->set_headset_profile_type( + static_cast<HeadsetProfileType>(i)); + headset_profile_connection_stats->set_num_times_connected( + num_times_connected); + } + } + pimpl_->headset_profile_connection_counts_.fill(0); } void BluetoothMetricsLogger::ResetSession() { diff --git a/system/osi/test/metrics_test.cc b/system/osi/test/metrics_test.cc index 15f6ad93e2603e418780dde81c53d0ee04274169..2c9762f5b41154a27213a4b2270d579fcf11509c 100644 --- a/system/osi/test/metrics_test.cc +++ b/system/osi/test/metrics_test.cc @@ -50,6 +50,8 @@ using bluetooth::metrics::BluetoothMetricsProto::ScanEvent_ScanTechnologyType; using bluetooth::metrics::BluetoothMetricsProto::ScanEvent_ScanEventType; using bluetooth::metrics::BluetoothMetricsProto::WakeEvent; using bluetooth::metrics::BluetoothMetricsProto::WakeEvent_WakeEventType; +using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType; +using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileConnectionStats; using system_bt_osi::BluetoothMetricsLogger; using system_bt_osi::A2dpSessionMetrics; @@ -408,7 +410,7 @@ TEST_F(BluetoothMetricsLoggerTest, PairEventTest) { BluetoothMetricsLogger::GetInstance()->LogPairEvent( 35, 12345, 42, system_bt_osi::DEVICE_TYPE_BREDR); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -420,7 +422,7 @@ TEST_F(BluetoothMetricsLoggerTest, WakeEventTest) { BluetoothMetricsLogger::GetInstance()->LogWakeEvent( system_bt_osi::WAKE_EVENT_ACQUIRED, "TEST_REQ", "TEST_NAME", 12345); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -437,7 +439,7 @@ TEST_F(BluetoothMetricsLoggerTest, WakeEventOverrunTest) { "TEST_REQ", "TEST_NAME", i); } std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -451,7 +453,7 @@ TEST_F(BluetoothMetricsLoggerTest, ScanEventTest) { BluetoothMetricsLogger::GetInstance()->LogScanEvent( false, "TEST_INITIATOR", system_bt_osi::SCAN_TECH_TYPE_BREDR, 42, 123456); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -469,7 +471,7 @@ TEST_F(BluetoothMetricsLoggerTest, BluetoothSessionTest) { BluetoothMetricsLogger::GetInstance()->LogBluetoothSessionEnd( system_bt_osi::DISCONNECT_REASON_UNKNOWN, 133456); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -486,7 +488,7 @@ TEST_F(BluetoothMetricsLoggerTest, BluetoothSessionDumpBeforeEndTest) { system_bt_osi::CONNECTION_TECHNOLOGY_TYPE_LE, time_get_os_boottime_ms()); sleep_ms(1000); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -513,7 +515,7 @@ TEST_F(BluetoothMetricsLoggerTest, BluetoothSessionStartBeforeEndTest) { system_bt_osi::CONNECTION_TECHNOLOGY_TYPE_LE, 0); sleep_ms(2000); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -579,7 +581,7 @@ TEST_F(BluetoothMetricsLoggerTest, A2DPSessionTwoUpdatesTest) { BluetoothMetricsLogger::GetInstance()->LogBluetoothSessionEnd( system_bt_osi::DISCONNECT_REASON_UNKNOWN, 133456); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -635,7 +637,7 @@ TEST_F(BluetoothMetricsLoggerTest, A2DPSessionTwoUpdatesSeparatedbyDumpTest) { BluetoothMetricsLogger::GetInstance()->LogA2dpSession(metrics1); sleep_ms(1000); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); ClearLog(); info = MakeDeviceInfo( @@ -655,7 +657,7 @@ TEST_F(BluetoothMetricsLoggerTest, A2DPSessionTwoUpdatesSeparatedbyDumpTest) { BluetoothMetricsLogger::GetInstance()->LogBluetoothSessionEnd( system_bt_osi::DISCONNECT_REASON_UNKNOWN, 0); msg_str.clear(); - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -714,7 +716,7 @@ TEST_F(BluetoothMetricsLoggerTest, A2DPSessionOnlyTest) { BluetoothMetricsLogger::GetInstance()->LogA2dpSession(metrics2); sleep_ms(1000); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } @@ -777,7 +779,7 @@ TEST_F(BluetoothMetricsLoggerTest, A2DPSessionDumpBeforeTwoUpdatesTest) { BTM_COD_MAJOR_AUDIO_TEST, system_bt_osi::DEVICE_TYPE_BREDR); sleep_ms(1000); std::string msg_str; - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); ClearLog(); info = MakeDeviceInfo( @@ -798,7 +800,94 @@ TEST_F(BluetoothMetricsLoggerTest, A2DPSessionDumpBeforeTwoUpdatesTest) { BluetoothMetricsLogger::GetInstance()->LogBluetoothSessionEnd( system_bt_osi::DISCONNECT_REASON_UNKNOWN, 0); msg_str.clear(); - BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str, true); + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); EXPECT_THAT(msg_str, StrEq(bt_log_str_)); } + +TEST_F(BluetoothMetricsLoggerTest, LogHeadsetProfileRfcConnectionTest) { + BluetoothMetricsLogger::GetInstance()->LogHeadsetProfileRfcConnection( + BTA_HSP_SERVICE_ID); + BluetoothMetricsLogger::GetInstance()->LogHeadsetProfileRfcConnection( + BTA_HFP_SERVICE_ID); + BluetoothMetricsLogger::GetInstance()->LogHeadsetProfileRfcConnection( + BTA_HFP_SERVICE_ID); + std::string msg_str; + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); + BluetoothLog* metrics = BluetoothLog::default_instance().New(); + metrics->ParseFromString(msg_str); + EXPECT_EQ(metrics->headset_profile_connection_stats_size(), 2); + bool hfp_correct = false; + bool hsp_correct = false; + for (const HeadsetProfileConnectionStats& headset_profile_connection_stats : + metrics->headset_profile_connection_stats()) { + switch (headset_profile_connection_stats.headset_profile_type()) { + case HeadsetProfileType::HFP: + EXPECT_EQ(headset_profile_connection_stats.num_times_connected(), 2); + hfp_correct = true; + break; + case HeadsetProfileType::HSP: + EXPECT_EQ(headset_profile_connection_stats.num_times_connected(), 1); + hsp_correct = true; + break; + default: + FAIL(); + } + } + EXPECT_TRUE(hfp_correct); + EXPECT_TRUE(hsp_correct); + metrics->clear_headset_profile_connection_stats(); + EXPECT_EQ(metrics->headset_profile_connection_stats_size(), 0); + msg_str.clear(); + // Verify that dump after clean up result in an empty list + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); + metrics->ParseFromString(msg_str); + EXPECT_EQ(metrics->headset_profile_connection_stats_size(), 0); + delete metrics; +} + +TEST_F(BluetoothMetricsLoggerTest, LogHeadsetProfileRfcConnectionErrorTest) { + BluetoothMetricsLogger::GetInstance()->LogHeadsetProfileRfcConnection( + BTA_HSP_SERVICE_ID); + BluetoothMetricsLogger::GetInstance()->LogHeadsetProfileRfcConnection( + BTA_HFP_SERVICE_ID); + BluetoothMetricsLogger::GetInstance()->LogHeadsetProfileRfcConnection( + BTA_BIP_SERVICE_ID); + BluetoothMetricsLogger::GetInstance()->LogHeadsetProfileRfcConnection( + BTA_HSP_SERVICE_ID); + std::string msg_str; + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); + BluetoothLog* metrics = BluetoothLog::default_instance().New(); + metrics->ParseFromString(msg_str); + EXPECT_EQ(metrics->headset_profile_connection_stats_size(), 3); + bool hfp_correct = false; + bool hsp_correct = false; + bool unknown_correct = false; + for (const HeadsetProfileConnectionStats& headset_profile_connection_stats : + metrics->headset_profile_connection_stats()) { + switch (headset_profile_connection_stats.headset_profile_type()) { + case HeadsetProfileType::HFP: + EXPECT_EQ(headset_profile_connection_stats.num_times_connected(), 1); + hfp_correct = true; + break; + case HeadsetProfileType::HSP: + EXPECT_EQ(headset_profile_connection_stats.num_times_connected(), 2); + hsp_correct = true; + break; + default: + EXPECT_EQ(headset_profile_connection_stats.num_times_connected(), 1); + unknown_correct = true; + break; + } + } + EXPECT_TRUE(hfp_correct); + EXPECT_TRUE(hsp_correct); + EXPECT_TRUE(unknown_correct); + metrics->clear_headset_profile_connection_stats(); + EXPECT_EQ(metrics->headset_profile_connection_stats_size(), 0); + // Verify that dump after clean up result in an empty list + BluetoothMetricsLogger::GetInstance()->WriteString(&msg_str); + metrics->ParseFromString(msg_str); + EXPECT_EQ(metrics->headset_profile_connection_stats_size(), 0); + delete metrics; +} }