1 /******************************************************************************
2 *
3 * Copyright 2016 Google, Inc.
4 *
5 * Licensed under the Apache License, Version 2.0 (the "License");
6 * you may not use this file except in compliance with the License.
7 * You may obtain a copy of the License at:
8 *
9 * http://www.apache.org/licenses/LICENSE-2.0
10 *
11 * Unless required by applicable law or agreed to in writing, software
12 * distributed under the License is distributed on an "AS IS" BASIS,
13 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14 * See the License for the specific language governing permissions and
15 * limitations under the License.
16 *
17 ******************************************************************************/
18
19 #include <unistd.h>
20 #include <algorithm>
21 #include <array>
22 #include <cerrno>
23 #include <chrono>
24 #include <cstdint>
25 #include <cstring>
26 #include <memory>
27 #include <mutex>
28
29 #include <base/base64.h>
30 #include <base/logging.h>
31 #include <include/hardware/bt_av.h>
32 #include <statslog.h>
33
34 #include "bluetooth/metrics/bluetooth.pb.h"
35 #include "osi/include/osi.h"
36 #include "stack/include/btm_api_types.h"
37
38 #include "address_obfuscator.h"
39 #include "leaky_bonded_queue.h"
40 #include "metric_id_allocator.h"
41 #include "metrics.h"
42 #include "time_util.h"
43
44 namespace bluetooth {
45
46 namespace common {
47
48 using bluetooth::metrics::BluetoothMetricsProto::A2DPSession;
49 using bluetooth::metrics::BluetoothMetricsProto::A2dpSourceCodec;
50 using bluetooth::metrics::BluetoothMetricsProto::BluetoothLog;
51 using bluetooth::metrics::BluetoothMetricsProto::BluetoothSession;
52 using bluetooth::metrics::BluetoothMetricsProto::
53 BluetoothSession_ConnectionTechnologyType;
54 using bluetooth::metrics::BluetoothMetricsProto::
55 BluetoothSession_DisconnectReasonType;
56 using bluetooth::metrics::BluetoothMetricsProto::DeviceInfo;
57 using bluetooth::metrics::BluetoothMetricsProto::DeviceInfo_DeviceType;
58 using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileConnectionStats;
59 using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType;
60 using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_ARRAYSIZE;
61 using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_IsValid;
62 using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_MAX;
63 using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_MIN;
64 using bluetooth::metrics::BluetoothMetricsProto::PairEvent;
65 using bluetooth::metrics::BluetoothMetricsProto::ScanEvent;
66 using bluetooth::metrics::BluetoothMetricsProto::ScanEvent_ScanEventType;
67 using bluetooth::metrics::BluetoothMetricsProto::ScanEvent_ScanTechnologyType;
68 using bluetooth::metrics::BluetoothMetricsProto::WakeEvent;
69 using bluetooth::metrics::BluetoothMetricsProto::WakeEvent_WakeEventType;
70
combine_averages(float avg_a,int64_t ct_a,float avg_b,int64_t ct_b)71 static float combine_averages(float avg_a, int64_t ct_a, float avg_b,
72 int64_t ct_b) {
73 if (ct_a > 0 && ct_b > 0) {
74 return (avg_a * ct_a + avg_b * ct_b) / (ct_a + ct_b);
75 } else if (ct_b > 0) {
76 return avg_b;
77 } else {
78 return avg_a;
79 }
80 }
81
combine_averages(int32_t avg_a,int64_t ct_a,int32_t avg_b,int64_t ct_b)82 static int32_t combine_averages(int32_t avg_a, int64_t ct_a, int32_t avg_b,
83 int64_t ct_b) {
84 if (ct_a > 0 && ct_b > 0) {
85 return (avg_a * ct_a + avg_b * ct_b) / (ct_a + ct_b);
86 } else if (ct_b > 0) {
87 return avg_b;
88 } else {
89 return avg_a;
90 }
91 }
92
Update(const A2dpSessionMetrics & metrics)93 void A2dpSessionMetrics::Update(const A2dpSessionMetrics& metrics) {
94 if (metrics.audio_duration_ms >= 0) {
95 audio_duration_ms = std::max(static_cast<int64_t>(0), audio_duration_ms);
96 audio_duration_ms += metrics.audio_duration_ms;
97 }
98 if (metrics.media_timer_min_ms >= 0) {
99 if (media_timer_min_ms < 0) {
100 media_timer_min_ms = metrics.media_timer_min_ms;
101 } else {
102 media_timer_min_ms =
103 std::min(media_timer_min_ms, metrics.media_timer_min_ms);
104 }
105 }
106 if (metrics.media_timer_max_ms >= 0) {
107 media_timer_max_ms =
108 std::max(media_timer_max_ms, metrics.media_timer_max_ms);
109 }
110 if (metrics.media_timer_avg_ms >= 0 && metrics.total_scheduling_count >= 0) {
111 if (media_timer_avg_ms < 0 || total_scheduling_count < 0) {
112 media_timer_avg_ms = metrics.media_timer_avg_ms;
113 total_scheduling_count = metrics.total_scheduling_count;
114 } else {
115 media_timer_avg_ms = combine_averages(
116 media_timer_avg_ms, total_scheduling_count,
117 metrics.media_timer_avg_ms, metrics.total_scheduling_count);
118 total_scheduling_count += metrics.total_scheduling_count;
119 }
120 }
121 if (metrics.buffer_overruns_max_count >= 0) {
122 buffer_overruns_max_count =
123 std::max(buffer_overruns_max_count, metrics.buffer_overruns_max_count);
124 }
125 if (metrics.buffer_overruns_total >= 0) {
126 buffer_overruns_total =
127 std::max(static_cast<int32_t>(0), buffer_overruns_total);
128 buffer_overruns_total += metrics.buffer_overruns_total;
129 }
130 if (metrics.buffer_underruns_average >= 0 &&
131 metrics.buffer_underruns_count >= 0) {
132 if (buffer_underruns_average < 0 || buffer_underruns_count < 0) {
133 buffer_underruns_average = metrics.buffer_underruns_average;
134 buffer_underruns_count = metrics.buffer_underruns_count;
135 } else {
136 buffer_underruns_average = combine_averages(
137 buffer_underruns_average, buffer_underruns_count,
138 metrics.buffer_underruns_average, metrics.buffer_underruns_count);
139 buffer_underruns_count += metrics.buffer_underruns_count;
140 }
141 }
142 if (codec_index < 0) {
143 codec_index = metrics.codec_index;
144 }
145 if (!is_a2dp_offload) {
146 is_a2dp_offload = metrics.is_a2dp_offload;
147 }
148 }
149
operator ==(const A2dpSessionMetrics & rhs) const150 bool A2dpSessionMetrics::operator==(const A2dpSessionMetrics& rhs) const {
151 return audio_duration_ms == rhs.audio_duration_ms &&
152 media_timer_min_ms == rhs.media_timer_min_ms &&
153 media_timer_max_ms == rhs.media_timer_max_ms &&
154 media_timer_avg_ms == rhs.media_timer_avg_ms &&
155 total_scheduling_count == rhs.total_scheduling_count &&
156 buffer_overruns_max_count == rhs.buffer_overruns_max_count &&
157 buffer_overruns_total == rhs.buffer_overruns_total &&
158 buffer_underruns_average == rhs.buffer_underruns_average &&
159 buffer_underruns_count == rhs.buffer_underruns_count &&
160 codec_index == rhs.codec_index &&
161 is_a2dp_offload == rhs.is_a2dp_offload;
162 }
163
get_device_type(device_type_t type)164 static DeviceInfo_DeviceType get_device_type(device_type_t type) {
165 switch (type) {
166 case DEVICE_TYPE_BREDR:
167 return DeviceInfo_DeviceType::DeviceInfo_DeviceType_DEVICE_TYPE_BREDR;
168 case DEVICE_TYPE_LE:
169 return DeviceInfo_DeviceType::DeviceInfo_DeviceType_DEVICE_TYPE_LE;
170 case DEVICE_TYPE_DUMO:
171 return DeviceInfo_DeviceType::DeviceInfo_DeviceType_DEVICE_TYPE_DUMO;
172 case DEVICE_TYPE_UNKNOWN:
173 default:
174 return DeviceInfo_DeviceType::DeviceInfo_DeviceType_DEVICE_TYPE_UNKNOWN;
175 }
176 }
177
get_connection_tech_type(connection_tech_t type)178 static BluetoothSession_ConnectionTechnologyType get_connection_tech_type(
179 connection_tech_t type) {
180 switch (type) {
181 case CONNECTION_TECHNOLOGY_TYPE_LE:
182 return BluetoothSession_ConnectionTechnologyType::
183 BluetoothSession_ConnectionTechnologyType_CONNECTION_TECHNOLOGY_TYPE_LE;
184 case CONNECTION_TECHNOLOGY_TYPE_BREDR:
185 return BluetoothSession_ConnectionTechnologyType::
186 BluetoothSession_ConnectionTechnologyType_CONNECTION_TECHNOLOGY_TYPE_BREDR;
187 case CONNECTION_TECHNOLOGY_TYPE_UNKNOWN:
188 default:
189 return BluetoothSession_ConnectionTechnologyType::
190 BluetoothSession_ConnectionTechnologyType_CONNECTION_TECHNOLOGY_TYPE_UNKNOWN;
191 }
192 }
193
get_scan_tech_type(scan_tech_t type)194 static ScanEvent_ScanTechnologyType get_scan_tech_type(scan_tech_t type) {
195 switch (type) {
196 case SCAN_TECH_TYPE_LE:
197 return ScanEvent_ScanTechnologyType::
198 ScanEvent_ScanTechnologyType_SCAN_TECH_TYPE_LE;
199 case SCAN_TECH_TYPE_BREDR:
200 return ScanEvent_ScanTechnologyType::
201 ScanEvent_ScanTechnologyType_SCAN_TECH_TYPE_BREDR;
202 case SCAN_TECH_TYPE_BOTH:
203 return ScanEvent_ScanTechnologyType::
204 ScanEvent_ScanTechnologyType_SCAN_TECH_TYPE_BOTH;
205 case SCAN_TYPE_UNKNOWN:
206 default:
207 return ScanEvent_ScanTechnologyType::
208 ScanEvent_ScanTechnologyType_SCAN_TYPE_UNKNOWN;
209 }
210 }
211
get_wake_event_type(wake_event_type_t type)212 static WakeEvent_WakeEventType get_wake_event_type(wake_event_type_t type) {
213 switch (type) {
214 case WAKE_EVENT_ACQUIRED:
215 return WakeEvent_WakeEventType::WakeEvent_WakeEventType_ACQUIRED;
216 case WAKE_EVENT_RELEASED:
217 return WakeEvent_WakeEventType::WakeEvent_WakeEventType_RELEASED;
218 case WAKE_EVENT_UNKNOWN:
219 default:
220 return WakeEvent_WakeEventType::WakeEvent_WakeEventType_UNKNOWN;
221 }
222 }
223
get_disconnect_reason_type(disconnect_reason_t type)224 static BluetoothSession_DisconnectReasonType get_disconnect_reason_type(
225 disconnect_reason_t type) {
226 switch (type) {
227 case DISCONNECT_REASON_METRICS_DUMP:
228 return BluetoothSession_DisconnectReasonType::
229 BluetoothSession_DisconnectReasonType_METRICS_DUMP;
230 case DISCONNECT_REASON_NEXT_START_WITHOUT_END_PREVIOUS:
231 return BluetoothSession_DisconnectReasonType::
232 BluetoothSession_DisconnectReasonType_NEXT_START_WITHOUT_END_PREVIOUS;
233 case DISCONNECT_REASON_UNKNOWN:
234 default:
235 return BluetoothSession_DisconnectReasonType::
236 BluetoothSession_DisconnectReasonType_UNKNOWN;
237 }
238 }
239
get_a2dp_source_codec(int64_t codec_index)240 static A2dpSourceCodec get_a2dp_source_codec(int64_t codec_index) {
241 switch (codec_index) {
242 case BTAV_A2DP_CODEC_INDEX_SOURCE_SBC:
243 return A2dpSourceCodec::A2DP_SOURCE_CODEC_SBC;
244 case BTAV_A2DP_CODEC_INDEX_SOURCE_AAC:
245 return A2dpSourceCodec::A2DP_SOURCE_CODEC_AAC;
246 case BTAV_A2DP_CODEC_INDEX_SOURCE_APTX:
247 return A2dpSourceCodec::A2DP_SOURCE_CODEC_APTX;
248 case BTAV_A2DP_CODEC_INDEX_SOURCE_APTX_HD:
249 return A2dpSourceCodec::A2DP_SOURCE_CODEC_APTX_HD;
250 case BTAV_A2DP_CODEC_INDEX_SOURCE_LDAC:
251 return A2dpSourceCodec::A2DP_SOURCE_CODEC_LDAC;
252 default:
253 return A2dpSourceCodec::A2DP_SOURCE_CODEC_UNKNOWN;
254 }
255 }
256
257 struct BluetoothMetricsLogger::impl {
implbluetooth::common::BluetoothMetricsLogger::impl258 impl(size_t max_bluetooth_session, size_t max_pair_event,
259 size_t max_wake_event, size_t max_scan_event)
260 : bt_session_queue_(
261 new LeakyBondedQueue<BluetoothSession>(max_bluetooth_session)),
262 pair_event_queue_(new LeakyBondedQueue<PairEvent>(max_pair_event)),
263 wake_event_queue_(new LeakyBondedQueue<WakeEvent>(max_wake_event)),
264 scan_event_queue_(new LeakyBondedQueue<ScanEvent>(max_scan_event)) {
265 bluetooth_log_ = BluetoothLog::default_instance().New();
266 headset_profile_connection_counts_.fill(0);
267 bluetooth_session_ = nullptr;
268 bluetooth_session_start_time_ms_ = 0;
269 a2dp_session_metrics_ = A2dpSessionMetrics();
270 }
271
272 /* Bluetooth log lock protected */
273 BluetoothLog* bluetooth_log_;
274 std::array<int, HeadsetProfileType_ARRAYSIZE>
275 headset_profile_connection_counts_;
276 std::recursive_mutex bluetooth_log_lock_;
277 /* End Bluetooth log lock protected */
278 /* Bluetooth session lock protected */
279 BluetoothSession* bluetooth_session_;
280 uint64_t bluetooth_session_start_time_ms_;
281 A2dpSessionMetrics a2dp_session_metrics_;
282 std::recursive_mutex bluetooth_session_lock_;
283 /* End bluetooth session lock protected */
284 std::unique_ptr<LeakyBondedQueue<BluetoothSession>> bt_session_queue_;
285 std::unique_ptr<LeakyBondedQueue<PairEvent>> pair_event_queue_;
286 std::unique_ptr<LeakyBondedQueue<WakeEvent>> wake_event_queue_;
287 std::unique_ptr<LeakyBondedQueue<ScanEvent>> scan_event_queue_;
288 };
289
BluetoothMetricsLogger()290 BluetoothMetricsLogger::BluetoothMetricsLogger()
291 : pimpl_(new impl(kMaxNumBluetoothSession, kMaxNumPairEvent,
292 kMaxNumWakeEvent, kMaxNumScanEvent)) {}
293
LogPairEvent(uint32_t disconnect_reason,uint64_t timestamp_ms,uint32_t device_class,device_type_t device_type)294 void BluetoothMetricsLogger::LogPairEvent(uint32_t disconnect_reason,
295 uint64_t timestamp_ms,
296 uint32_t device_class,
297 device_type_t device_type) {
298 PairEvent* event = new PairEvent();
299 DeviceInfo* info = event->mutable_device_paired_with();
300 info->set_device_class(device_class);
301 info->set_device_type(get_device_type(device_type));
302 event->set_disconnect_reason(disconnect_reason);
303 event->set_event_time_millis(timestamp_ms);
304 pimpl_->pair_event_queue_->Enqueue(event);
305 {
306 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
307 pimpl_->bluetooth_log_->set_num_pair_event(
308 pimpl_->bluetooth_log_->num_pair_event() + 1);
309 }
310 }
311
LogWakeEvent(wake_event_type_t type,const std::string & requestor,const std::string & name,uint64_t timestamp_ms)312 void BluetoothMetricsLogger::LogWakeEvent(wake_event_type_t type,
313 const std::string& requestor,
314 const std::string& name,
315 uint64_t timestamp_ms) {
316 WakeEvent* event = new WakeEvent();
317 event->set_wake_event_type(get_wake_event_type(type));
318 event->set_requestor(requestor);
319 event->set_name(name);
320 event->set_event_time_millis(timestamp_ms);
321 pimpl_->wake_event_queue_->Enqueue(event);
322 {
323 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
324 pimpl_->bluetooth_log_->set_num_wake_event(
325 pimpl_->bluetooth_log_->num_wake_event() + 1);
326 }
327 }
328
LogScanEvent(bool start,const std::string & initator,scan_tech_t type,uint32_t results,uint64_t timestamp_ms)329 void BluetoothMetricsLogger::LogScanEvent(bool start,
330 const std::string& initator,
331 scan_tech_t type, uint32_t results,
332 uint64_t timestamp_ms) {
333 ScanEvent* event = new ScanEvent();
334 if (start) {
335 event->set_scan_event_type(ScanEvent::SCAN_EVENT_START);
336 } else {
337 event->set_scan_event_type(ScanEvent::SCAN_EVENT_STOP);
338 }
339 event->set_initiator(initator);
340 event->set_scan_technology_type(get_scan_tech_type(type));
341 event->set_number_results(results);
342 event->set_event_time_millis(timestamp_ms);
343 pimpl_->scan_event_queue_->Enqueue(event);
344 {
345 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
346 pimpl_->bluetooth_log_->set_num_scan_event(
347 pimpl_->bluetooth_log_->num_scan_event() + 1);
348 }
349 }
350
LogBluetoothSessionStart(connection_tech_t connection_tech_type,uint64_t timestamp_ms)351 void BluetoothMetricsLogger::LogBluetoothSessionStart(
352 connection_tech_t connection_tech_type, uint64_t timestamp_ms) {
353 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
354 if (pimpl_->bluetooth_session_ != nullptr) {
355 LogBluetoothSessionEnd(DISCONNECT_REASON_NEXT_START_WITHOUT_END_PREVIOUS,
356 0);
357 }
358 if (timestamp_ms == 0) {
359 timestamp_ms = bluetooth::common::time_get_os_boottime_ms();
360 }
361 pimpl_->bluetooth_session_start_time_ms_ = timestamp_ms;
362 pimpl_->bluetooth_session_ = new BluetoothSession();
363 pimpl_->bluetooth_session_->set_connection_technology_type(
364 get_connection_tech_type(connection_tech_type));
365 }
366
LogBluetoothSessionEnd(disconnect_reason_t disconnect_reason,uint64_t timestamp_ms)367 void BluetoothMetricsLogger::LogBluetoothSessionEnd(
368 disconnect_reason_t disconnect_reason, uint64_t timestamp_ms) {
369 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
370 if (pimpl_->bluetooth_session_ == nullptr) {
371 return;
372 }
373 if (timestamp_ms == 0) {
374 timestamp_ms = bluetooth::common::time_get_os_boottime_ms();
375 }
376 int64_t session_duration_sec =
377 (timestamp_ms - pimpl_->bluetooth_session_start_time_ms_) / 1000;
378 pimpl_->bluetooth_session_->set_session_duration_sec(session_duration_sec);
379 pimpl_->bluetooth_session_->set_disconnect_reason_type(
380 get_disconnect_reason_type(disconnect_reason));
381 pimpl_->bt_session_queue_->Enqueue(pimpl_->bluetooth_session_);
382 pimpl_->bluetooth_session_ = nullptr;
383 pimpl_->a2dp_session_metrics_ = A2dpSessionMetrics();
384 {
385 std::lock_guard<std::recursive_mutex> log_lock(pimpl_->bluetooth_log_lock_);
386 pimpl_->bluetooth_log_->set_num_bluetooth_session(
387 pimpl_->bluetooth_log_->num_bluetooth_session() + 1);
388 }
389 }
390
LogBluetoothSessionDeviceInfo(uint32_t device_class,device_type_t device_type)391 void BluetoothMetricsLogger::LogBluetoothSessionDeviceInfo(
392 uint32_t device_class, device_type_t device_type) {
393 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
394 if (pimpl_->bluetooth_session_ == nullptr) {
395 LogBluetoothSessionStart(CONNECTION_TECHNOLOGY_TYPE_UNKNOWN, 0);
396 }
397 DeviceInfo* info = pimpl_->bluetooth_session_->mutable_device_connected_to();
398 info->set_device_class(device_class);
399 info->set_device_type(DeviceInfo::DEVICE_TYPE_BREDR);
400 }
401
LogA2dpSession(const A2dpSessionMetrics & a2dp_session_metrics)402 void BluetoothMetricsLogger::LogA2dpSession(
403 const A2dpSessionMetrics& a2dp_session_metrics) {
404 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
405 if (pimpl_->bluetooth_session_ == nullptr) {
406 // When no bluetooth session exist, create one on system's behalf
407 // Set connection type: for A2DP it is always BR/EDR
408 LogBluetoothSessionStart(CONNECTION_TECHNOLOGY_TYPE_BREDR, 0);
409 LogBluetoothSessionDeviceInfo(BTM_COD_MAJOR_AUDIO, DEVICE_TYPE_BREDR);
410 }
411 // Accumulate metrics
412 pimpl_->a2dp_session_metrics_.Update(a2dp_session_metrics);
413 // Get or allocate new A2DP session object
414 A2DPSession* a2dp_session =
415 pimpl_->bluetooth_session_->mutable_a2dp_session();
416 a2dp_session->set_audio_duration_millis(
417 pimpl_->a2dp_session_metrics_.audio_duration_ms);
418 a2dp_session->set_media_timer_min_millis(
419 pimpl_->a2dp_session_metrics_.media_timer_min_ms);
420 a2dp_session->set_media_timer_max_millis(
421 pimpl_->a2dp_session_metrics_.media_timer_max_ms);
422 a2dp_session->set_media_timer_avg_millis(
423 pimpl_->a2dp_session_metrics_.media_timer_avg_ms);
424 a2dp_session->set_buffer_overruns_max_count(
425 pimpl_->a2dp_session_metrics_.buffer_overruns_max_count);
426 a2dp_session->set_buffer_overruns_total(
427 pimpl_->a2dp_session_metrics_.buffer_overruns_total);
428 a2dp_session->set_buffer_underruns_average(
429 pimpl_->a2dp_session_metrics_.buffer_underruns_average);
430 a2dp_session->set_buffer_underruns_count(
431 pimpl_->a2dp_session_metrics_.buffer_underruns_count);
432 a2dp_session->set_source_codec(
433 get_a2dp_source_codec(pimpl_->a2dp_session_metrics_.codec_index));
434 a2dp_session->set_is_a2dp_offload(
435 pimpl_->a2dp_session_metrics_.is_a2dp_offload);
436 }
437
LogHeadsetProfileRfcConnection(tBTA_SERVICE_ID service_id)438 void BluetoothMetricsLogger::LogHeadsetProfileRfcConnection(
439 tBTA_SERVICE_ID service_id) {
440 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
441 switch (service_id) {
442 case BTA_HSP_SERVICE_ID:
443 pimpl_->headset_profile_connection_counts_[HeadsetProfileType::HSP]++;
444 break;
445 case BTA_HFP_SERVICE_ID:
446 pimpl_->headset_profile_connection_counts_[HeadsetProfileType::HFP]++;
447 break;
448 default:
449 pimpl_->headset_profile_connection_counts_
450 [HeadsetProfileType::HEADSET_PROFILE_UNKNOWN]++;
451 break;
452 }
453 return;
454 }
455
WriteString(std::string * serialized)456 void BluetoothMetricsLogger::WriteString(std::string* serialized) {
457 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
458 LOG(INFO) << __func__ << ": building metrics";
459 Build();
460 LOG(INFO) << __func__ << ": serializing metrics";
461 if (!pimpl_->bluetooth_log_->SerializeToString(serialized)) {
462 LOG(ERROR) << __func__ << ": error serializing metrics";
463 }
464 // Always clean up log objects
465 pimpl_->bluetooth_log_->Clear();
466 }
467
WriteBase64String(std::string * serialized)468 void BluetoothMetricsLogger::WriteBase64String(std::string* serialized) {
469 this->WriteString(serialized);
470 base::Base64Encode(*serialized, serialized);
471 }
472
WriteBase64(int fd)473 void BluetoothMetricsLogger::WriteBase64(int fd) {
474 std::string protoBase64;
475 this->WriteBase64String(&protoBase64);
476 ssize_t ret;
477 OSI_NO_INTR(ret = write(fd, protoBase64.c_str(), protoBase64.size()));
478 if (ret == -1) {
479 LOG(ERROR) << __func__
480 << ": error writing to dumpsys fd: " << strerror(errno) << " ("
481 << std::to_string(errno) << ")";
482 }
483 }
484
CutoffSession()485 void BluetoothMetricsLogger::CutoffSession() {
486 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
487 if (pimpl_->bluetooth_session_ != nullptr) {
488 BluetoothSession* new_bt_session =
489 new BluetoothSession(*pimpl_->bluetooth_session_);
490 new_bt_session->clear_a2dp_session();
491 new_bt_session->clear_rfcomm_session();
492 LogBluetoothSessionEnd(DISCONNECT_REASON_METRICS_DUMP, 0);
493 pimpl_->bluetooth_session_ = new_bt_session;
494 pimpl_->bluetooth_session_start_time_ms_ =
495 bluetooth::common::time_get_os_boottime_ms();
496 pimpl_->a2dp_session_metrics_ = A2dpSessionMetrics();
497 }
498 }
499
Build()500 void BluetoothMetricsLogger::Build() {
501 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
502 CutoffSession();
503 BluetoothLog* bluetooth_log = pimpl_->bluetooth_log_;
504 while (!pimpl_->bt_session_queue_->Empty() &&
505 static_cast<size_t>(bluetooth_log->session_size()) <=
506 pimpl_->bt_session_queue_->Capacity()) {
507 bluetooth_log->mutable_session()->AddAllocated(
508 pimpl_->bt_session_queue_->Dequeue());
509 }
510 while (!pimpl_->pair_event_queue_->Empty() &&
511 static_cast<size_t>(bluetooth_log->pair_event_size()) <=
512 pimpl_->pair_event_queue_->Capacity()) {
513 bluetooth_log->mutable_pair_event()->AddAllocated(
514 pimpl_->pair_event_queue_->Dequeue());
515 }
516 while (!pimpl_->scan_event_queue_->Empty() &&
517 static_cast<size_t>(bluetooth_log->scan_event_size()) <=
518 pimpl_->scan_event_queue_->Capacity()) {
519 bluetooth_log->mutable_scan_event()->AddAllocated(
520 pimpl_->scan_event_queue_->Dequeue());
521 }
522 while (!pimpl_->wake_event_queue_->Empty() &&
523 static_cast<size_t>(bluetooth_log->wake_event_size()) <=
524 pimpl_->wake_event_queue_->Capacity()) {
525 bluetooth_log->mutable_wake_event()->AddAllocated(
526 pimpl_->wake_event_queue_->Dequeue());
527 }
528 while (!pimpl_->bt_session_queue_->Empty() &&
529 static_cast<size_t>(bluetooth_log->wake_event_size()) <=
530 pimpl_->wake_event_queue_->Capacity()) {
531 bluetooth_log->mutable_wake_event()->AddAllocated(
532 pimpl_->wake_event_queue_->Dequeue());
533 }
534 for (size_t i = 0; i < HeadsetProfileType_ARRAYSIZE; ++i) {
535 int num_times_connected = pimpl_->headset_profile_connection_counts_[i];
536 if (HeadsetProfileType_IsValid(i) && num_times_connected > 0) {
537 HeadsetProfileConnectionStats* headset_profile_connection_stats =
538 bluetooth_log->add_headset_profile_connection_stats();
539 // Able to static_cast because HeadsetProfileType_IsValid(i) is true
540 headset_profile_connection_stats->set_headset_profile_type(
541 static_cast<HeadsetProfileType>(i));
542 headset_profile_connection_stats->set_num_times_connected(
543 num_times_connected);
544 }
545 }
546 pimpl_->headset_profile_connection_counts_.fill(0);
547 }
548
ResetSession()549 void BluetoothMetricsLogger::ResetSession() {
550 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
551 if (pimpl_->bluetooth_session_ != nullptr) {
552 delete pimpl_->bluetooth_session_;
553 pimpl_->bluetooth_session_ = nullptr;
554 }
555 pimpl_->bluetooth_session_start_time_ms_ = 0;
556 pimpl_->a2dp_session_metrics_ = A2dpSessionMetrics();
557 }
558
ResetLog()559 void BluetoothMetricsLogger::ResetLog() {
560 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
561 pimpl_->bluetooth_log_->Clear();
562 }
563
Reset()564 void BluetoothMetricsLogger::Reset() {
565 ResetSession();
566 ResetLog();
567 pimpl_->bt_session_queue_->Clear();
568 pimpl_->pair_event_queue_->Clear();
569 pimpl_->wake_event_queue_->Clear();
570 pimpl_->scan_event_queue_->Clear();
571 }
572
LogLinkLayerConnectionEvent(const RawAddress * address,uint32_t connection_handle,android::bluetooth::DirectionEnum direction,uint16_t link_type,uint32_t hci_cmd,uint16_t hci_event,uint16_t hci_ble_event,uint16_t cmd_status,uint16_t reason_code)573 void LogLinkLayerConnectionEvent(const RawAddress* address,
574 uint32_t connection_handle,
575 android::bluetooth::DirectionEnum direction,
576 uint16_t link_type, uint32_t hci_cmd,
577 uint16_t hci_event, uint16_t hci_ble_event,
578 uint16_t cmd_status, uint16_t reason_code) {
579 std::string obfuscated_id;
580 int metric_id = 0;
581 if (address != nullptr) {
582 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(*address);
583 metric_id = MetricIdAllocator::GetInstance().AllocateId(*address);
584 }
585 // nullptr and size 0 represent missing value for obfuscated_id
586 android::util::BytesField bytes_field(
587 address != nullptr ? obfuscated_id.c_str() : nullptr,
588 address != nullptr ? obfuscated_id.size() : 0);
589 int ret = android::util::stats_write(
590 android::util::BLUETOOTH_LINK_LAYER_CONNECTION_EVENT, bytes_field,
591 connection_handle, direction, link_type, hci_cmd, hci_event,
592 hci_ble_event, cmd_status, reason_code, metric_id);
593 if (ret < 0) {
594 LOG(WARNING) << __func__ << ": failed to log status " << loghex(cmd_status)
595 << ", reason " << loghex(reason_code) << " from cmd "
596 << loghex(hci_cmd) << ", event " << loghex(hci_event)
597 << ", ble_event " << loghex(hci_ble_event) << " for "
598 << address << ", handle " << connection_handle << ", type "
599 << loghex(link_type) << ", error " << ret;
600 }
601 }
602
LogHciTimeoutEvent(uint32_t hci_cmd)603 void LogHciTimeoutEvent(uint32_t hci_cmd) {
604 int ret =
605 android::util::stats_write(android::util::BLUETOOTH_HCI_TIMEOUT_REPORTED,
606 static_cast<int64_t>(hci_cmd));
607 if (ret < 0) {
608 LOG(WARNING) << __func__ << ": failed for opcode " << loghex(hci_cmd)
609 << ", error " << ret;
610 }
611 }
612
LogRemoteVersionInfo(uint16_t handle,uint8_t status,uint8_t version,uint16_t manufacturer_name,uint16_t subversion)613 void LogRemoteVersionInfo(uint16_t handle, uint8_t status, uint8_t version,
614 uint16_t manufacturer_name, uint16_t subversion) {
615 int ret = android::util::stats_write(
616 android::util::BLUETOOTH_REMOTE_VERSION_INFO_REPORTED, handle, status,
617 version, manufacturer_name, subversion);
618 if (ret < 0) {
619 LOG(WARNING) << __func__ << ": failed for handle " << handle << ", status "
620 << loghex(status) << ", version " << loghex(version)
621 << ", manufacturer_name " << loghex(manufacturer_name)
622 << ", subversion " << loghex(subversion) << ", error " << ret;
623 }
624 }
625
LogA2dpAudioUnderrunEvent(const RawAddress & address,uint64_t encoding_interval_millis,int num_missing_pcm_bytes)626 void LogA2dpAudioUnderrunEvent(const RawAddress& address,
627 uint64_t encoding_interval_millis,
628 int num_missing_pcm_bytes) {
629 std::string obfuscated_id;
630 int metric_id = 0;
631 if (!address.IsEmpty()) {
632 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
633 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
634 }
635 // nullptr and size 0 represent missing value for obfuscated_id
636 android::util::BytesField bytes_field(
637 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
638 address.IsEmpty() ? 0 : obfuscated_id.size());
639 int64_t encoding_interval_nanos = encoding_interval_millis * 1000000;
640 int ret = android::util::stats_write(
641 android::util::BLUETOOTH_A2DP_AUDIO_UNDERRUN_REPORTED, bytes_field,
642 encoding_interval_nanos, num_missing_pcm_bytes, metric_id);
643 if (ret < 0) {
644 LOG(WARNING) << __func__ << ": failed for " << address
645 << ", encoding_interval_nanos " << encoding_interval_nanos
646 << ", num_missing_pcm_bytes " << num_missing_pcm_bytes
647 << ", error " << ret;
648 }
649 }
650
LogA2dpAudioOverrunEvent(const RawAddress & address,uint64_t encoding_interval_millis,int num_dropped_buffers,int num_dropped_encoded_frames,int num_dropped_encoded_bytes)651 void LogA2dpAudioOverrunEvent(const RawAddress& address,
652 uint64_t encoding_interval_millis,
653 int num_dropped_buffers,
654 int num_dropped_encoded_frames,
655 int num_dropped_encoded_bytes) {
656 std::string obfuscated_id;
657 int metric_id = 0;
658 if (!address.IsEmpty()) {
659 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
660 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
661 }
662 // nullptr and size 0 represent missing value for obfuscated_id
663 android::util::BytesField bytes_field(
664 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
665 address.IsEmpty() ? 0 : obfuscated_id.size());
666 int64_t encoding_interval_nanos = encoding_interval_millis * 1000000;
667 int ret = android::util::stats_write(
668 android::util::BLUETOOTH_A2DP_AUDIO_OVERRUN_REPORTED, bytes_field,
669 encoding_interval_nanos, num_dropped_buffers, num_dropped_encoded_frames,
670 num_dropped_encoded_bytes, metric_id);
671 if (ret < 0) {
672 LOG(WARNING) << __func__ << ": failed to log for " << address
673 << ", encoding_interval_nanos " << encoding_interval_nanos
674 << ", num_dropped_buffers " << num_dropped_buffers
675 << ", num_dropped_encoded_frames "
676 << num_dropped_encoded_frames << ", num_dropped_encoded_bytes "
677 << num_dropped_encoded_bytes << ", error " << ret;
678 }
679 }
680
LogReadRssiResult(const RawAddress & address,uint16_t handle,uint32_t cmd_status,int8_t rssi)681 void LogReadRssiResult(const RawAddress& address, uint16_t handle,
682 uint32_t cmd_status, int8_t rssi) {
683 std::string obfuscated_id;
684 int metric_id = 0;
685 if (!address.IsEmpty()) {
686 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
687 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
688 }
689 // nullptr and size 0 represent missing value for obfuscated_id
690 android::util::BytesField bytes_field(
691 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
692 address.IsEmpty() ? 0 : obfuscated_id.size());
693 int ret = android::util::stats_write(
694 android::util::BLUETOOTH_DEVICE_RSSI_REPORTED, bytes_field, handle,
695 cmd_status, rssi, metric_id);
696 if (ret < 0) {
697 LOG(WARNING) << __func__ << ": failed for " << address << ", handle "
698 << handle << ", status " << loghex(cmd_status) << ", rssi "
699 << rssi << " dBm, error " << ret;
700 }
701 }
702
LogReadFailedContactCounterResult(const RawAddress & address,uint16_t handle,uint32_t cmd_status,int32_t failed_contact_counter)703 void LogReadFailedContactCounterResult(const RawAddress& address,
704 uint16_t handle, uint32_t cmd_status,
705 int32_t failed_contact_counter) {
706 std::string obfuscated_id;
707 int metric_id = 0;
708 if (!address.IsEmpty()) {
709 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
710 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
711 }
712 // nullptr and size 0 represent missing value for obfuscated_id
713 android::util::BytesField bytes_field(
714 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
715 address.IsEmpty() ? 0 : obfuscated_id.size());
716 int ret = android::util::stats_write(
717 android::util::BLUETOOTH_DEVICE_FAILED_CONTACT_COUNTER_REPORTED,
718 bytes_field, handle, cmd_status, failed_contact_counter, metric_id);
719 if (ret < 0) {
720 LOG(WARNING) << __func__ << ": failed for " << address << ", handle "
721 << handle << ", status " << loghex(cmd_status)
722 << ", failed_contact_counter " << failed_contact_counter
723 << " packets, error " << ret;
724 }
725 }
726
LogReadTxPowerLevelResult(const RawAddress & address,uint16_t handle,uint32_t cmd_status,int32_t transmit_power_level)727 void LogReadTxPowerLevelResult(const RawAddress& address, uint16_t handle,
728 uint32_t cmd_status,
729 int32_t transmit_power_level) {
730 std::string obfuscated_id;
731 int metric_id = 0;
732 if (!address.IsEmpty()) {
733 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
734 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
735 }
736 // nullptr and size 0 represent missing value for obfuscated_id
737 android::util::BytesField bytes_field(
738 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
739 address.IsEmpty() ? 0 : obfuscated_id.size());
740 int ret = android::util::stats_write(
741 android::util::BLUETOOTH_DEVICE_TX_POWER_LEVEL_REPORTED, bytes_field,
742 handle, cmd_status, transmit_power_level, metric_id);
743 if (ret < 0) {
744 LOG(WARNING) << __func__ << ": failed for " << address << ", handle "
745 << handle << ", status " << loghex(cmd_status)
746 << ", transmit_power_level " << transmit_power_level
747 << " packets, error " << ret;
748 }
749 }
750
LogSmpPairingEvent(const RawAddress & address,uint8_t smp_cmd,android::bluetooth::DirectionEnum direction,uint8_t smp_fail_reason)751 void LogSmpPairingEvent(const RawAddress& address, uint8_t smp_cmd,
752 android::bluetooth::DirectionEnum direction,
753 uint8_t smp_fail_reason) {
754 std::string obfuscated_id;
755 int metric_id = 0;
756 if (!address.IsEmpty()) {
757 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
758 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
759 }
760 // nullptr and size 0 represent missing value for obfuscated_id
761 android::util::BytesField obfuscated_id_field(
762 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
763 address.IsEmpty() ? 0 : obfuscated_id.size());
764 int ret = android::util::stats_write(
765 android::util::BLUETOOTH_SMP_PAIRING_EVENT_REPORTED, obfuscated_id_field,
766 smp_cmd, direction, smp_fail_reason, metric_id);
767 if (ret < 0) {
768 LOG(WARNING) << __func__ << ": failed for " << address << ", smp_cmd "
769 << loghex(smp_cmd) << ", direction " << direction
770 << ", smp_fail_reason " << loghex(smp_fail_reason)
771 << ", error " << ret;
772 }
773 }
774
LogClassicPairingEvent(const RawAddress & address,uint16_t handle,uint32_t hci_cmd,uint16_t hci_event,uint16_t cmd_status,uint16_t reason_code,int64_t event_value)775 void LogClassicPairingEvent(const RawAddress& address, uint16_t handle, uint32_t hci_cmd, uint16_t hci_event,
776 uint16_t cmd_status, uint16_t reason_code, int64_t event_value) {
777 std::string obfuscated_id;
778 int metric_id = 0;
779 if (!address.IsEmpty()) {
780 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
781 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
782 }
783 // nullptr and size 0 represent missing value for obfuscated_id
784 android::util::BytesField obfuscated_id_field(
785 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
786 address.IsEmpty() ? 0 : obfuscated_id.size());
787 int ret = android::util::stats_write(
788 android::util::BLUETOOTH_CLASSIC_PAIRING_EVENT_REPORTED,
789 obfuscated_id_field, handle, hci_cmd, hci_event, cmd_status, reason_code,
790 event_value, metric_id);
791 if (ret < 0) {
792 LOG(WARNING) << __func__ << ": failed for " << address << ", handle " << handle << ", hci_cmd " << loghex(hci_cmd)
793 << ", hci_event " << loghex(hci_event) << ", cmd_status " << loghex(cmd_status) << ", reason "
794 << loghex(reason_code) << ", event_value " << event_value << ", error " << ret;
795 }
796 }
797
LogSdpAttribute(const RawAddress & address,uint16_t protocol_uuid,uint16_t attribute_id,size_t attribute_size,const char * attribute_value)798 void LogSdpAttribute(const RawAddress& address, uint16_t protocol_uuid,
799 uint16_t attribute_id, size_t attribute_size,
800 const char* attribute_value) {
801 std::string obfuscated_id;
802 int metric_id = 0;
803 if (!address.IsEmpty()) {
804 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
805 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
806 }
807 // nullptr and size 0 represent missing value for obfuscated_id
808 android::util::BytesField obfuscated_id_field(
809 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
810 address.IsEmpty() ? 0 : obfuscated_id.size());
811 android::util::BytesField attribute_field(attribute_value, attribute_size);
812 int ret = android::util::stats_write(
813 android::util::BLUETOOTH_SDP_ATTRIBUTE_REPORTED, obfuscated_id_field,
814 protocol_uuid, attribute_id, attribute_field, metric_id);
815 if (ret < 0) {
816 LOG(WARNING) << __func__ << ": failed for " << address << ", protocol_uuid "
817 << loghex(protocol_uuid) << ", attribute_id "
818 << loghex(attribute_id) << ", error " << ret;
819 }
820 }
821
LogSocketConnectionState(const RawAddress & address,int port,int type,android::bluetooth::SocketConnectionstateEnum connection_state,int64_t tx_bytes,int64_t rx_bytes,int uid,int server_port,android::bluetooth::SocketRoleEnum socket_role)822 void LogSocketConnectionState(
823 const RawAddress& address, int port, int type,
824 android::bluetooth::SocketConnectionstateEnum connection_state,
825 int64_t tx_bytes, int64_t rx_bytes, int uid, int server_port,
826 android::bluetooth::SocketRoleEnum socket_role) {
827 std::string obfuscated_id;
828 int metric_id = 0;
829 if (!address.IsEmpty()) {
830 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
831 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
832 }
833 // nullptr and size 0 represent missing value for obfuscated_id
834 android::util::BytesField obfuscated_id_field(
835 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
836 address.IsEmpty() ? 0 : obfuscated_id.size());
837 int ret = android::util::stats_write(
838 android::util::BLUETOOTH_SOCKET_CONNECTION_STATE_CHANGED,
839 obfuscated_id_field, port, type, connection_state, tx_bytes, rx_bytes,
840 uid, server_port, socket_role, metric_id);
841 if (ret < 0) {
842 LOG(WARNING) << __func__ << ": failed for " << address << ", port " << port
843 << ", type " << type << ", state " << connection_state
844 << ", tx_bytes " << tx_bytes << ", rx_bytes " << rx_bytes
845 << ", uid " << uid << ", server_port " << server_port
846 << ", socket_role " << socket_role << ", error " << ret;
847 }
848 }
849
LogManufacturerInfo(const RawAddress & address,android::bluetooth::DeviceInfoSrcEnum source_type,const std::string & source_name,const std::string & manufacturer,const std::string & model,const std::string & hardware_version,const std::string & software_version)850 void LogManufacturerInfo(const RawAddress& address,
851 android::bluetooth::DeviceInfoSrcEnum source_type,
852 const std::string& source_name,
853 const std::string& manufacturer,
854 const std::string& model,
855 const std::string& hardware_version,
856 const std::string& software_version) {
857 std::string obfuscated_id;
858 int metric_id = 0;
859 if (!address.IsEmpty()) {
860 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
861 metric_id = MetricIdAllocator::GetInstance().AllocateId(address);
862 }
863 // nullptr and size 0 represent missing value for obfuscated_id
864 android::util::BytesField obfuscated_id_field(
865 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
866 address.IsEmpty() ? 0 : obfuscated_id.size());
867 int ret = android::util::stats_write(
868 android::util::BLUETOOTH_DEVICE_INFO_REPORTED, obfuscated_id_field,
869 source_type, source_name.c_str(), manufacturer.c_str(), model.c_str(),
870 hardware_version.c_str(), software_version.c_str(), metric_id);
871 if (ret < 0) {
872 LOG(WARNING) << __func__ << ": failed for " << address << ", source_type "
873 << source_type << ", source_name " << source_name
874 << ", manufacturer " << manufacturer << ", model " << model
875 << ", hardware_version " << hardware_version
876 << ", software_version " << software_version << ", error "
877 << ret;
878 }
879 }
880
881 } // namespace common
882
883 } // namespace bluetooth
884