blob: 8355e03eb895594077d247d8afa4f2ebd16aa33a [file] [log] [blame]
Marie Janssena84a4ee2016-01-15 16:14:14 -08001/******************************************************************************
2 *
Jakub Pawlowski3b10fdd2017-09-18 09:00:20 -07003 * Copyright 2016 Google, Inc.
Marie Janssena84a4ee2016-01-15 16:14:14 -08004 *
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 ******************************************************************************/
Marie Janssena84a4ee2016-01-15 16:14:14 -080018
Jack He777228a2016-12-08 19:29:00 -080019#include <unistd.h>
20#include <algorithm>
Jack He7ebb85a2018-04-02 13:04:58 -070021#include <array>
Jack He777228a2016-12-08 19:29:00 -080022#include <cerrno>
23#include <chrono>
24#include <cstdint>
25#include <cstring>
26#include <memory>
27#include <mutex>
Marie Janssena84a4ee2016-01-15 16:14:14 -080028
Jack He777228a2016-12-08 19:29:00 -080029#include <base/base64.h>
30#include <base/logging.h>
Jack Heeeb9f352018-06-08 20:13:23 -070031#include <include/hardware/bt_av.h>
Jack He0d4807d2018-12-20 15:46:17 -080032#include <statslog.h>
Marie Janssena84a4ee2016-01-15 16:14:14 -080033
Jack He9a30a9f2018-03-03 00:03:25 -080034#include "bluetooth/metrics/bluetooth.pb.h"
Marie Janssena84a4ee2016-01-15 16:14:14 -080035#include "osi/include/osi.h"
Jack He777228a2016-12-08 19:29:00 -080036#include "stack/include/btm_api_types.h"
Marie Janssena84a4ee2016-01-15 16:14:14 -080037
Jack He0d4807d2018-12-20 15:46:17 -080038#include "address_obfuscator.h"
Jack He42823982018-08-15 12:38:37 -070039#include "leaky_bonded_queue.h"
40#include "metrics.h"
41#include "time_util.h"
Jack He777228a2016-12-08 19:29:00 -080042
Jack He42823982018-08-15 12:38:37 -070043namespace bluetooth {
44
45namespace common {
Marie Janssena84a4ee2016-01-15 16:14:14 -080046
Jack He9a30a9f2018-03-03 00:03:25 -080047using bluetooth::metrics::BluetoothMetricsProto::A2DPSession;
Jack Heeeb9f352018-06-08 20:13:23 -070048using bluetooth::metrics::BluetoothMetricsProto::A2dpSourceCodec;
Jack He9a30a9f2018-03-03 00:03:25 -080049using bluetooth::metrics::BluetoothMetricsProto::BluetoothLog;
50using bluetooth::metrics::BluetoothMetricsProto::BluetoothSession;
51using bluetooth::metrics::BluetoothMetricsProto::
52 BluetoothSession_ConnectionTechnologyType;
53using bluetooth::metrics::BluetoothMetricsProto::
54 BluetoothSession_DisconnectReasonType;
55using bluetooth::metrics::BluetoothMetricsProto::DeviceInfo;
56using bluetooth::metrics::BluetoothMetricsProto::DeviceInfo_DeviceType;
Jack He42823982018-08-15 12:38:37 -070057using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileConnectionStats;
Jack He7ebb85a2018-04-02 13:04:58 -070058using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType;
Jack He7ebb85a2018-04-02 13:04:58 -070059using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_ARRAYSIZE;
60using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_IsValid;
Jack He42823982018-08-15 12:38:37 -070061using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_MAX;
62using bluetooth::metrics::BluetoothMetricsProto::HeadsetProfileType_MIN;
63using bluetooth::metrics::BluetoothMetricsProto::PairEvent;
64using bluetooth::metrics::BluetoothMetricsProto::ScanEvent;
65using bluetooth::metrics::BluetoothMetricsProto::ScanEvent_ScanEventType;
66using bluetooth::metrics::BluetoothMetricsProto::ScanEvent_ScanTechnologyType;
67using bluetooth::metrics::BluetoothMetricsProto::WakeEvent;
68using bluetooth::metrics::BluetoothMetricsProto::WakeEvent_WakeEventType;
Jack He777228a2016-12-08 19:29:00 -080069
70static float combine_averages(float avg_a, int64_t ct_a, float avg_b,
71 int64_t ct_b) {
72 if (ct_a > 0 && ct_b > 0) {
73 return (avg_a * ct_a + avg_b * ct_b) / (ct_a + ct_b);
74 } else if (ct_b > 0) {
75 return avg_b;
76 } else {
77 return avg_a;
Marie Janssena84a4ee2016-01-15 16:14:14 -080078 }
79}
80
Jack He777228a2016-12-08 19:29:00 -080081static int32_t combine_averages(int32_t avg_a, int64_t ct_a, int32_t avg_b,
82 int64_t ct_b) {
83 if (ct_a > 0 && ct_b > 0) {
84 return (avg_a * ct_a + avg_b * ct_b) / (ct_a + ct_b);
85 } else if (ct_b > 0) {
86 return avg_b;
87 } else {
88 return avg_a;
89 }
90}
Marie Janssena84a4ee2016-01-15 16:14:14 -080091
Jack He777228a2016-12-08 19:29:00 -080092void A2dpSessionMetrics::Update(const A2dpSessionMetrics& metrics) {
Jack He723bef82017-01-20 11:17:44 -080093 if (metrics.audio_duration_ms >= 0) {
Jack He777228a2016-12-08 19:29:00 -080094 audio_duration_ms = std::max(static_cast<int64_t>(0), audio_duration_ms);
95 audio_duration_ms += metrics.audio_duration_ms;
96 }
Jack He723bef82017-01-20 11:17:44 -080097 if (metrics.media_timer_min_ms >= 0) {
Jack He777228a2016-12-08 19:29:00 -080098 if (media_timer_min_ms < 0) {
99 media_timer_min_ms = metrics.media_timer_min_ms;
100 } else {
101 media_timer_min_ms =
102 std::min(media_timer_min_ms, metrics.media_timer_min_ms);
103 }
104 }
Jack He723bef82017-01-20 11:17:44 -0800105 if (metrics.media_timer_max_ms >= 0) {
Jack He777228a2016-12-08 19:29:00 -0800106 media_timer_max_ms =
107 std::max(media_timer_max_ms, metrics.media_timer_max_ms);
108 }
Jack He723bef82017-01-20 11:17:44 -0800109 if (metrics.media_timer_avg_ms >= 0 && metrics.total_scheduling_count >= 0) {
Jack He777228a2016-12-08 19:29:00 -0800110 if (media_timer_avg_ms < 0 || total_scheduling_count < 0) {
111 media_timer_avg_ms = metrics.media_timer_avg_ms;
112 total_scheduling_count = metrics.total_scheduling_count;
113 } else {
114 media_timer_avg_ms = combine_averages(
115 media_timer_avg_ms, total_scheduling_count,
116 metrics.media_timer_avg_ms, metrics.total_scheduling_count);
117 total_scheduling_count += metrics.total_scheduling_count;
118 }
119 }
Jack He723bef82017-01-20 11:17:44 -0800120 if (metrics.buffer_overruns_max_count >= 0) {
Jack He777228a2016-12-08 19:29:00 -0800121 buffer_overruns_max_count =
122 std::max(buffer_overruns_max_count, metrics.buffer_overruns_max_count);
123 }
Jack He723bef82017-01-20 11:17:44 -0800124 if (metrics.buffer_overruns_total >= 0) {
Jack He777228a2016-12-08 19:29:00 -0800125 buffer_overruns_total =
126 std::max(static_cast<int32_t>(0), buffer_overruns_total);
127 buffer_overruns_total += metrics.buffer_overruns_total;
128 }
Jack He723bef82017-01-20 11:17:44 -0800129 if (metrics.buffer_underruns_average >= 0 &&
130 metrics.buffer_underruns_count >= 0) {
Jack He777228a2016-12-08 19:29:00 -0800131 if (buffer_underruns_average < 0 || buffer_underruns_count < 0) {
132 buffer_underruns_average = metrics.buffer_underruns_average;
133 buffer_underruns_count = metrics.buffer_underruns_count;
134 } else {
135 buffer_underruns_average = combine_averages(
Jack He723bef82017-01-20 11:17:44 -0800136 buffer_underruns_average, buffer_underruns_count,
137 metrics.buffer_underruns_average, metrics.buffer_underruns_count);
Jack He777228a2016-12-08 19:29:00 -0800138 buffer_underruns_count += metrics.buffer_underruns_count;
139 }
140 }
Jack Heeeb9f352018-06-08 20:13:23 -0700141 if (codec_index < 0) {
142 codec_index = metrics.codec_index;
143 }
144 if (!is_a2dp_offload) {
145 is_a2dp_offload = metrics.is_a2dp_offload;
146 }
Jack He777228a2016-12-08 19:29:00 -0800147}
Marie Janssena84a4ee2016-01-15 16:14:14 -0800148
Jack He777228a2016-12-08 19:29:00 -0800149bool A2dpSessionMetrics::operator==(const A2dpSessionMetrics& rhs) const {
150 return audio_duration_ms == rhs.audio_duration_ms &&
151 media_timer_min_ms == rhs.media_timer_min_ms &&
152 media_timer_max_ms == rhs.media_timer_max_ms &&
153 media_timer_avg_ms == rhs.media_timer_avg_ms &&
154 total_scheduling_count == rhs.total_scheduling_count &&
155 buffer_overruns_max_count == rhs.buffer_overruns_max_count &&
156 buffer_overruns_total == rhs.buffer_overruns_total &&
157 buffer_underruns_average == rhs.buffer_underruns_average &&
Jack Heeeb9f352018-06-08 20:13:23 -0700158 buffer_underruns_count == rhs.buffer_underruns_count &&
159 codec_index == rhs.codec_index &&
160 is_a2dp_offload == rhs.is_a2dp_offload;
Jack He777228a2016-12-08 19:29:00 -0800161}
162
163static DeviceInfo_DeviceType get_device_type(device_type_t type) {
164 switch (type) {
165 case DEVICE_TYPE_BREDR:
166 return DeviceInfo_DeviceType::DeviceInfo_DeviceType_DEVICE_TYPE_BREDR;
167 case DEVICE_TYPE_LE:
168 return DeviceInfo_DeviceType::DeviceInfo_DeviceType_DEVICE_TYPE_LE;
169 case DEVICE_TYPE_DUMO:
170 return DeviceInfo_DeviceType::DeviceInfo_DeviceType_DEVICE_TYPE_DUMO;
171 case DEVICE_TYPE_UNKNOWN:
172 default:
173 return DeviceInfo_DeviceType::DeviceInfo_DeviceType_DEVICE_TYPE_UNKNOWN;
174 }
175}
176
177static BluetoothSession_ConnectionTechnologyType get_connection_tech_type(
178 connection_tech_t type) {
179 switch (type) {
180 case CONNECTION_TECHNOLOGY_TYPE_LE:
181 return BluetoothSession_ConnectionTechnologyType::
182 BluetoothSession_ConnectionTechnologyType_CONNECTION_TECHNOLOGY_TYPE_LE;
183 case CONNECTION_TECHNOLOGY_TYPE_BREDR:
184 return BluetoothSession_ConnectionTechnologyType::
185 BluetoothSession_ConnectionTechnologyType_CONNECTION_TECHNOLOGY_TYPE_BREDR;
186 case CONNECTION_TECHNOLOGY_TYPE_UNKNOWN:
187 default:
188 return BluetoothSession_ConnectionTechnologyType::
189 BluetoothSession_ConnectionTechnologyType_CONNECTION_TECHNOLOGY_TYPE_UNKNOWN;
190 }
191}
192
193static ScanEvent_ScanTechnologyType get_scan_tech_type(scan_tech_t type) {
194 switch (type) {
195 case SCAN_TECH_TYPE_LE:
196 return ScanEvent_ScanTechnologyType::
197 ScanEvent_ScanTechnologyType_SCAN_TECH_TYPE_LE;
198 case SCAN_TECH_TYPE_BREDR:
199 return ScanEvent_ScanTechnologyType::
200 ScanEvent_ScanTechnologyType_SCAN_TECH_TYPE_BREDR;
201 case SCAN_TECH_TYPE_BOTH:
202 return ScanEvent_ScanTechnologyType::
203 ScanEvent_ScanTechnologyType_SCAN_TECH_TYPE_BOTH;
204 case SCAN_TYPE_UNKNOWN:
205 default:
206 return ScanEvent_ScanTechnologyType::
207 ScanEvent_ScanTechnologyType_SCAN_TYPE_UNKNOWN;
208 }
209}
210
211static WakeEvent_WakeEventType get_wake_event_type(wake_event_type_t type) {
212 switch (type) {
213 case WAKE_EVENT_ACQUIRED:
214 return WakeEvent_WakeEventType::WakeEvent_WakeEventType_ACQUIRED;
215 case WAKE_EVENT_RELEASED:
216 return WakeEvent_WakeEventType::WakeEvent_WakeEventType_RELEASED;
217 case WAKE_EVENT_UNKNOWN:
218 default:
219 return WakeEvent_WakeEventType::WakeEvent_WakeEventType_UNKNOWN;
220 }
221}
222
Jack He9bebcc02017-01-17 15:41:30 -0800223static BluetoothSession_DisconnectReasonType get_disconnect_reason_type(
224 disconnect_reason_t type) {
225 switch (type) {
226 case DISCONNECT_REASON_METRICS_DUMP:
227 return BluetoothSession_DisconnectReasonType::
228 BluetoothSession_DisconnectReasonType_METRICS_DUMP;
229 case DISCONNECT_REASON_NEXT_START_WITHOUT_END_PREVIOUS:
230 return BluetoothSession_DisconnectReasonType::
231 BluetoothSession_DisconnectReasonType_NEXT_START_WITHOUT_END_PREVIOUS;
232 case DISCONNECT_REASON_UNKNOWN:
233 default:
234 return BluetoothSession_DisconnectReasonType::
235 BluetoothSession_DisconnectReasonType_UNKNOWN;
236 }
237}
238
Jack Heeeb9f352018-06-08 20:13:23 -0700239static A2dpSourceCodec get_a2dp_source_codec(int64_t codec_index) {
240 switch (codec_index) {
241 case BTAV_A2DP_CODEC_INDEX_SOURCE_SBC:
242 return A2dpSourceCodec::A2DP_SOURCE_CODEC_SBC;
243 case BTAV_A2DP_CODEC_INDEX_SOURCE_AAC:
244 return A2dpSourceCodec::A2DP_SOURCE_CODEC_AAC;
245 case BTAV_A2DP_CODEC_INDEX_SOURCE_APTX:
246 return A2dpSourceCodec::A2DP_SOURCE_CODEC_APTX;
247 case BTAV_A2DP_CODEC_INDEX_SOURCE_APTX_HD:
248 return A2dpSourceCodec::A2DP_SOURCE_CODEC_APTX_HD;
249 case BTAV_A2DP_CODEC_INDEX_SOURCE_LDAC:
250 return A2dpSourceCodec::A2DP_SOURCE_CODEC_LDAC;
251 default:
252 return A2dpSourceCodec::A2DP_SOURCE_CODEC_UNKNOWN;
253 }
254}
255
Jack He777228a2016-12-08 19:29:00 -0800256struct BluetoothMetricsLogger::impl {
257 impl(size_t max_bluetooth_session, size_t max_pair_event,
258 size_t max_wake_event, size_t max_scan_event)
259 : bt_session_queue_(
260 new LeakyBondedQueue<BluetoothSession>(max_bluetooth_session)),
261 pair_event_queue_(new LeakyBondedQueue<PairEvent>(max_pair_event)),
262 wake_event_queue_(new LeakyBondedQueue<WakeEvent>(max_wake_event)),
263 scan_event_queue_(new LeakyBondedQueue<ScanEvent>(max_scan_event)) {
264 bluetooth_log_ = BluetoothLog::default_instance().New();
Jack He7ebb85a2018-04-02 13:04:58 -0700265 headset_profile_connection_counts_.fill(0);
Jack He777228a2016-12-08 19:29:00 -0800266 bluetooth_session_ = nullptr;
267 bluetooth_session_start_time_ms_ = 0;
268 a2dp_session_metrics_ = A2dpSessionMetrics();
269 }
270
271 /* Bluetooth log lock protected */
272 BluetoothLog* bluetooth_log_;
Jack He7ebb85a2018-04-02 13:04:58 -0700273 std::array<int, HeadsetProfileType_ARRAYSIZE>
274 headset_profile_connection_counts_;
Jack He777228a2016-12-08 19:29:00 -0800275 std::recursive_mutex bluetooth_log_lock_;
276 /* End Bluetooth log lock protected */
277 /* Bluetooth session lock protected */
278 BluetoothSession* bluetooth_session_;
279 uint64_t bluetooth_session_start_time_ms_;
280 A2dpSessionMetrics a2dp_session_metrics_;
281 std::recursive_mutex bluetooth_session_lock_;
282 /* End bluetooth session lock protected */
283 std::unique_ptr<LeakyBondedQueue<BluetoothSession>> bt_session_queue_;
284 std::unique_ptr<LeakyBondedQueue<PairEvent>> pair_event_queue_;
285 std::unique_ptr<LeakyBondedQueue<WakeEvent>> wake_event_queue_;
286 std::unique_ptr<LeakyBondedQueue<ScanEvent>> scan_event_queue_;
287};
288
289BluetoothMetricsLogger::BluetoothMetricsLogger()
Jack He9bebcc02017-01-17 15:41:30 -0800290 : pimpl_(new impl(kMaxNumBluetoothSession, kMaxNumPairEvent,
291 kMaxNumWakeEvent, kMaxNumScanEvent)) {}
Jack He777228a2016-12-08 19:29:00 -0800292
293void BluetoothMetricsLogger::LogPairEvent(uint32_t disconnect_reason,
294 uint64_t timestamp_ms,
295 uint32_t device_class,
296 device_type_t device_type) {
297 PairEvent* event = new PairEvent();
Myles Watson914a9dc2016-10-19 13:15:34 -0700298 DeviceInfo* info = event->mutable_device_paired_with();
Marie Janssena84a4ee2016-01-15 16:14:14 -0800299 info->set_device_class(device_class);
Jack He777228a2016-12-08 19:29:00 -0800300 info->set_device_type(get_device_type(device_type));
Marie Janssena84a4ee2016-01-15 16:14:14 -0800301 event->set_disconnect_reason(disconnect_reason);
Marie Janssena84a4ee2016-01-15 16:14:14 -0800302 event->set_event_time_millis(timestamp_ms);
Jack He777228a2016-12-08 19:29:00 -0800303 pimpl_->pair_event_queue_->Enqueue(event);
Jack He9bebcc02017-01-17 15:41:30 -0800304 {
305 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
306 pimpl_->bluetooth_log_->set_num_pair_event(
307 pimpl_->bluetooth_log_->num_pair_event() + 1);
308 }
Marie Janssena84a4ee2016-01-15 16:14:14 -0800309}
310
Jack He777228a2016-12-08 19:29:00 -0800311void BluetoothMetricsLogger::LogWakeEvent(wake_event_type_t type,
312 const std::string& requestor,
313 const std::string& name,
314 uint64_t timestamp_ms) {
315 WakeEvent* event = new WakeEvent();
316 event->set_wake_event_type(get_wake_event_type(type));
317 event->set_requestor(requestor);
318 event->set_name(name);
Pavlin Radoslavov9aa6f122016-02-17 15:42:38 -0800319 event->set_event_time_millis(timestamp_ms);
Jack He777228a2016-12-08 19:29:00 -0800320 pimpl_->wake_event_queue_->Enqueue(event);
Jack He9bebcc02017-01-17 15:41:30 -0800321 {
322 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
323 pimpl_->bluetooth_log_->set_num_wake_event(
324 pimpl_->bluetooth_log_->num_wake_event() + 1);
325 }
Marie Janssena84a4ee2016-01-15 16:14:14 -0800326}
327
Jack He777228a2016-12-08 19:29:00 -0800328void BluetoothMetricsLogger::LogScanEvent(bool start,
329 const std::string& initator,
330 scan_tech_t type, uint32_t results,
331 uint64_t timestamp_ms) {
332 ScanEvent* event = new ScanEvent();
333 if (start) {
Marie Janssena84a4ee2016-01-15 16:14:14 -0800334 event->set_scan_event_type(ScanEvent::SCAN_EVENT_START);
Jack He777228a2016-12-08 19:29:00 -0800335 } else {
Marie Janssena84a4ee2016-01-15 16:14:14 -0800336 event->set_scan_event_type(ScanEvent::SCAN_EVENT_STOP);
Jack He777228a2016-12-08 19:29:00 -0800337 }
338 event->set_initiator(initator);
339 event->set_scan_technology_type(get_scan_tech_type(type));
Marie Janssena84a4ee2016-01-15 16:14:14 -0800340 event->set_number_results(results);
Marie Janssena84a4ee2016-01-15 16:14:14 -0800341 event->set_event_time_millis(timestamp_ms);
Jack He777228a2016-12-08 19:29:00 -0800342 pimpl_->scan_event_queue_->Enqueue(event);
Jack He9bebcc02017-01-17 15:41:30 -0800343 {
344 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
345 pimpl_->bluetooth_log_->set_num_scan_event(
346 pimpl_->bluetooth_log_->num_scan_event() + 1);
347 }
Marie Janssena84a4ee2016-01-15 16:14:14 -0800348}
349
Jack He777228a2016-12-08 19:29:00 -0800350void BluetoothMetricsLogger::LogBluetoothSessionStart(
351 connection_tech_t connection_tech_type, uint64_t timestamp_ms) {
352 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
353 if (pimpl_->bluetooth_session_ != nullptr) {
Jack He9bebcc02017-01-17 15:41:30 -0800354 LogBluetoothSessionEnd(DISCONNECT_REASON_NEXT_START_WITHOUT_END_PREVIOUS,
Jack He777228a2016-12-08 19:29:00 -0800355 0);
356 }
357 if (timestamp_ms == 0) {
Jack He42823982018-08-15 12:38:37 -0700358 timestamp_ms = bluetooth::common::time_get_os_boottime_ms();
Jack He777228a2016-12-08 19:29:00 -0800359 }
360 pimpl_->bluetooth_session_start_time_ms_ = timestamp_ms;
361 pimpl_->bluetooth_session_ = new BluetoothSession();
362 pimpl_->bluetooth_session_->set_connection_technology_type(
363 get_connection_tech_type(connection_tech_type));
364}
Pavlin Radoslavov9aa6f122016-02-17 15:42:38 -0800365
Jack He777228a2016-12-08 19:29:00 -0800366void BluetoothMetricsLogger::LogBluetoothSessionEnd(
Jack He9bebcc02017-01-17 15:41:30 -0800367 disconnect_reason_t disconnect_reason, uint64_t timestamp_ms) {
Jack He777228a2016-12-08 19:29:00 -0800368 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
369 if (pimpl_->bluetooth_session_ == nullptr) {
370 return;
371 }
372 if (timestamp_ms == 0) {
Jack He42823982018-08-15 12:38:37 -0700373 timestamp_ms = bluetooth::common::time_get_os_boottime_ms();
Jack He777228a2016-12-08 19:29:00 -0800374 }
375 int64_t session_duration_sec =
376 (timestamp_ms - pimpl_->bluetooth_session_start_time_ms_) / 1000;
377 pimpl_->bluetooth_session_->set_session_duration_sec(session_duration_sec);
Jack He9bebcc02017-01-17 15:41:30 -0800378 pimpl_->bluetooth_session_->set_disconnect_reason_type(
379 get_disconnect_reason_type(disconnect_reason));
Jack He777228a2016-12-08 19:29:00 -0800380 pimpl_->bt_session_queue_->Enqueue(pimpl_->bluetooth_session_);
381 pimpl_->bluetooth_session_ = nullptr;
Jack Heeeb9f352018-06-08 20:13:23 -0700382 pimpl_->a2dp_session_metrics_ = A2dpSessionMetrics();
Jack He9bebcc02017-01-17 15:41:30 -0800383 {
384 std::lock_guard<std::recursive_mutex> log_lock(pimpl_->bluetooth_log_lock_);
385 pimpl_->bluetooth_log_->set_num_bluetooth_session(
386 pimpl_->bluetooth_log_->num_bluetooth_session() + 1);
387 }
Jack He777228a2016-12-08 19:29:00 -0800388}
Pavlin Radoslavov9aa6f122016-02-17 15:42:38 -0800389
Jack He777228a2016-12-08 19:29:00 -0800390void BluetoothMetricsLogger::LogBluetoothSessionDeviceInfo(
391 uint32_t device_class, device_type_t device_type) {
392 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
393 if (pimpl_->bluetooth_session_ == nullptr) {
394 LogBluetoothSessionStart(CONNECTION_TECHNOLOGY_TYPE_UNKNOWN, 0);
395 }
396 DeviceInfo* info = pimpl_->bluetooth_session_->mutable_device_connected_to();
Pavlin Radoslavov9aa6f122016-02-17 15:42:38 -0800397 info->set_device_class(device_class);
398 info->set_device_type(DeviceInfo::DEVICE_TYPE_BREDR);
Pavlin Radoslavov9aa6f122016-02-17 15:42:38 -0800399}
400
Jack He777228a2016-12-08 19:29:00 -0800401void BluetoothMetricsLogger::LogA2dpSession(
402 const A2dpSessionMetrics& a2dp_session_metrics) {
403 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
404 if (pimpl_->bluetooth_session_ == nullptr) {
405 // When no bluetooth session exist, create one on system's behalf
406 // Set connection type: for A2DP it is always BR/EDR
407 LogBluetoothSessionStart(CONNECTION_TECHNOLOGY_TYPE_BREDR, 0);
408 LogBluetoothSessionDeviceInfo(BTM_COD_MAJOR_AUDIO, DEVICE_TYPE_BREDR);
409 }
410 // Accumulate metrics
411 pimpl_->a2dp_session_metrics_.Update(a2dp_session_metrics);
412 // Get or allocate new A2DP session object
413 A2DPSession* a2dp_session =
414 pimpl_->bluetooth_session_->mutable_a2dp_session();
415 a2dp_session->set_audio_duration_millis(
416 pimpl_->a2dp_session_metrics_.audio_duration_ms);
417 a2dp_session->set_media_timer_min_millis(
418 pimpl_->a2dp_session_metrics_.media_timer_min_ms);
419 a2dp_session->set_media_timer_max_millis(
420 pimpl_->a2dp_session_metrics_.media_timer_max_ms);
421 a2dp_session->set_media_timer_avg_millis(
422 pimpl_->a2dp_session_metrics_.media_timer_avg_ms);
423 a2dp_session->set_buffer_overruns_max_count(
424 pimpl_->a2dp_session_metrics_.buffer_overruns_max_count);
425 a2dp_session->set_buffer_overruns_total(
426 pimpl_->a2dp_session_metrics_.buffer_overruns_total);
427 a2dp_session->set_buffer_underruns_average(
428 pimpl_->a2dp_session_metrics_.buffer_underruns_average);
429 a2dp_session->set_buffer_underruns_count(
430 pimpl_->a2dp_session_metrics_.buffer_underruns_count);
Jack Heeeb9f352018-06-08 20:13:23 -0700431 a2dp_session->set_source_codec(
432 get_a2dp_source_codec(pimpl_->a2dp_session_metrics_.codec_index));
433 a2dp_session->set_is_a2dp_offload(
434 pimpl_->a2dp_session_metrics_.is_a2dp_offload);
Jack He777228a2016-12-08 19:29:00 -0800435}
Marie Janssena84a4ee2016-01-15 16:14:14 -0800436
Jack He7ebb85a2018-04-02 13:04:58 -0700437void BluetoothMetricsLogger::LogHeadsetProfileRfcConnection(
438 tBTA_SERVICE_ID service_id) {
439 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
440 switch (service_id) {
441 case BTA_HSP_SERVICE_ID:
442 pimpl_->headset_profile_connection_counts_[HeadsetProfileType::HSP]++;
443 break;
444 case BTA_HFP_SERVICE_ID:
445 pimpl_->headset_profile_connection_counts_[HeadsetProfileType::HFP]++;
446 break;
447 default:
448 pimpl_->headset_profile_connection_counts_
449 [HeadsetProfileType::HEADSET_PROFILE_UNKNOWN]++;
450 break;
451 }
452 return;
453}
454
455void BluetoothMetricsLogger::WriteString(std::string* serialized) {
Jack He777228a2016-12-08 19:29:00 -0800456 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
Jack He42823982018-08-15 12:38:37 -0700457 LOG(INFO) << __func__ << ": building metrics";
Jack He777228a2016-12-08 19:29:00 -0800458 Build();
Jack He42823982018-08-15 12:38:37 -0700459 LOG(INFO) << __func__ << ": serializing metrics";
Jack He777228a2016-12-08 19:29:00 -0800460 if (!pimpl_->bluetooth_log_->SerializeToString(serialized)) {
Jack He42823982018-08-15 12:38:37 -0700461 LOG(ERROR) << __func__ << ": error serializing metrics";
Marie Janssena84a4ee2016-01-15 16:14:14 -0800462 }
Jack He7ebb85a2018-04-02 13:04:58 -0700463 // Always clean up log objects
464 pimpl_->bluetooth_log_->Clear();
Jack He777228a2016-12-08 19:29:00 -0800465}
Ajay Panickerfe357dc2016-02-18 12:24:10 -0800466
Jack He7ebb85a2018-04-02 13:04:58 -0700467void BluetoothMetricsLogger::WriteBase64String(std::string* serialized) {
468 this->WriteString(serialized);
Jack He777228a2016-12-08 19:29:00 -0800469 base::Base64Encode(*serialized, serialized);
470}
471
Jack He7ebb85a2018-04-02 13:04:58 -0700472void BluetoothMetricsLogger::WriteBase64(int fd) {
Ajay Panicker4336ba52016-02-17 18:18:00 -0800473 std::string protoBase64;
Jack He7ebb85a2018-04-02 13:04:58 -0700474 this->WriteBase64String(&protoBase64);
Pavlin Radoslavovc608acf2016-05-12 11:36:44 -0700475 ssize_t ret;
476 OSI_NO_INTR(ret = write(fd, protoBase64.c_str(), protoBase64.size()));
477 if (ret == -1) {
Jack He42823982018-08-15 12:38:37 -0700478 LOG(ERROR) << __func__
479 << ": error writing to dumpsys fd: " << strerror(errno) << " ("
480 << std::to_string(errno) << ")";
Marie Janssena84a4ee2016-01-15 16:14:14 -0800481 }
Marie Janssena84a4ee2016-01-15 16:14:14 -0800482}
Jack He777228a2016-12-08 19:29:00 -0800483
484void BluetoothMetricsLogger::CutoffSession() {
485 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
486 if (pimpl_->bluetooth_session_ != nullptr) {
487 BluetoothSession* new_bt_session =
488 new BluetoothSession(*pimpl_->bluetooth_session_);
489 new_bt_session->clear_a2dp_session();
490 new_bt_session->clear_rfcomm_session();
Jack He9bebcc02017-01-17 15:41:30 -0800491 LogBluetoothSessionEnd(DISCONNECT_REASON_METRICS_DUMP, 0);
Jack He777228a2016-12-08 19:29:00 -0800492 pimpl_->bluetooth_session_ = new_bt_session;
Jack He42823982018-08-15 12:38:37 -0700493 pimpl_->bluetooth_session_start_time_ms_ =
494 bluetooth::common::time_get_os_boottime_ms();
Jack He777228a2016-12-08 19:29:00 -0800495 pimpl_->a2dp_session_metrics_ = A2dpSessionMetrics();
496 }
497}
498
499void BluetoothMetricsLogger::Build() {
500 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
501 CutoffSession();
502 BluetoothLog* bluetooth_log = pimpl_->bluetooth_log_;
503 while (!pimpl_->bt_session_queue_->Empty() &&
504 static_cast<size_t>(bluetooth_log->session_size()) <=
505 pimpl_->bt_session_queue_->Capacity()) {
506 bluetooth_log->mutable_session()->AddAllocated(
507 pimpl_->bt_session_queue_->Dequeue());
508 }
509 while (!pimpl_->pair_event_queue_->Empty() &&
510 static_cast<size_t>(bluetooth_log->pair_event_size()) <=
511 pimpl_->pair_event_queue_->Capacity()) {
512 bluetooth_log->mutable_pair_event()->AddAllocated(
513 pimpl_->pair_event_queue_->Dequeue());
514 }
515 while (!pimpl_->scan_event_queue_->Empty() &&
516 static_cast<size_t>(bluetooth_log->scan_event_size()) <=
517 pimpl_->scan_event_queue_->Capacity()) {
518 bluetooth_log->mutable_scan_event()->AddAllocated(
519 pimpl_->scan_event_queue_->Dequeue());
520 }
521 while (!pimpl_->wake_event_queue_->Empty() &&
522 static_cast<size_t>(bluetooth_log->wake_event_size()) <=
523 pimpl_->wake_event_queue_->Capacity()) {
524 bluetooth_log->mutable_wake_event()->AddAllocated(
525 pimpl_->wake_event_queue_->Dequeue());
526 }
527 while (!pimpl_->bt_session_queue_->Empty() &&
528 static_cast<size_t>(bluetooth_log->wake_event_size()) <=
529 pimpl_->wake_event_queue_->Capacity()) {
530 bluetooth_log->mutable_wake_event()->AddAllocated(
531 pimpl_->wake_event_queue_->Dequeue());
532 }
Jack He7ebb85a2018-04-02 13:04:58 -0700533 for (size_t i = 0; i < HeadsetProfileType_ARRAYSIZE; ++i) {
534 int num_times_connected = pimpl_->headset_profile_connection_counts_[i];
535 if (HeadsetProfileType_IsValid(i) && num_times_connected > 0) {
536 HeadsetProfileConnectionStats* headset_profile_connection_stats =
537 bluetooth_log->add_headset_profile_connection_stats();
538 // Able to static_cast because HeadsetProfileType_IsValid(i) is true
539 headset_profile_connection_stats->set_headset_profile_type(
540 static_cast<HeadsetProfileType>(i));
541 headset_profile_connection_stats->set_num_times_connected(
542 num_times_connected);
543 }
544 }
545 pimpl_->headset_profile_connection_counts_.fill(0);
Jack He777228a2016-12-08 19:29:00 -0800546}
547
548void BluetoothMetricsLogger::ResetSession() {
549 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_session_lock_);
550 if (pimpl_->bluetooth_session_ != nullptr) {
551 delete pimpl_->bluetooth_session_;
552 pimpl_->bluetooth_session_ = nullptr;
553 }
554 pimpl_->bluetooth_session_start_time_ms_ = 0;
555 pimpl_->a2dp_session_metrics_ = A2dpSessionMetrics();
556}
557
558void BluetoothMetricsLogger::ResetLog() {
559 std::lock_guard<std::recursive_mutex> lock(pimpl_->bluetooth_log_lock_);
560 pimpl_->bluetooth_log_->Clear();
561}
562
563void BluetoothMetricsLogger::Reset() {
564 ResetSession();
565 ResetLog();
566 pimpl_->bt_session_queue_->Clear();
567 pimpl_->pair_event_queue_->Clear();
568 pimpl_->wake_event_queue_->Clear();
569 pimpl_->scan_event_queue_->Clear();
570}
571
Jack He0d4807d2018-12-20 15:46:17 -0800572void LogLinkLayerConnectionEvent(const RawAddress* address,
573 uint32_t connection_handle,
574 android::bluetooth::DirectionEnum direction,
575 uint32_t link_type, uint32_t hci_cmd,
576 uint32_t hci_event, uint32_t hci_ble_event,
577 uint32_t cmd_status, uint32_t reason_code) {
578 std::string obfuscated_id;
579 if (address != nullptr) {
580 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(*address);
581 }
582 // nullptr and size 0 represent missing value for obfuscated_id
583 android::util::BytesField bytes_field(
584 address != nullptr ? obfuscated_id.c_str() : nullptr,
585 address != nullptr ? obfuscated_id.size() : 0);
586 int ret = android::util::stats_write(
587 android::util::BLUETOOTH_LINK_LAYER_CONNECTION_EVENT, bytes_field,
588 connection_handle, direction, link_type, hci_cmd, hci_event,
589 hci_ble_event, cmd_status, reason_code);
590 if (ret < 0) {
591 LOG(WARNING) << __func__ << ": failed to log status 0x"
592 << loghex(cmd_status) << ", reason 0x" << loghex(reason_code)
593 << " from cmd 0x" << loghex(hci_cmd) << ", event 0x"
594 << loghex(hci_event) << ", ble_event 0x"
595 << loghex(hci_ble_event) << " for " << address << ", handle "
596 << connection_handle << ", error " << ret;
597 }
598}
599
Jack He0e818cf2019-01-20 23:16:45 -0800600void LogHciTimeoutEvent(uint32_t hci_cmd) {
601 int ret =
602 android::util::stats_write(android::util::BLUETOOTH_HCI_TIMEOUT_REPORTED,
603 static_cast<int64_t>(hci_cmd));
604 if (ret < 0) {
605 LOG(WARNING) << __func__ << ": failed for opcode " << loghex(hci_cmd)
606 << ", error " << ret;
607 }
608}
609
Jack He078c8a82019-01-29 14:49:34 -0800610void LogRemoteVersionInfo(uint16_t handle, uint8_t status, uint8_t version,
611 uint16_t manufacturer_name, uint16_t subversion) {
612 int ret = android::util::stats_write(
613 android::util::BLUETOOTH_REMOTE_VERSION_INFO_REPORTED, handle, status,
614 version, manufacturer_name, subversion);
615 if (ret < 0) {
616 LOG(WARNING) << __func__ << ": failed for handle " << handle << ", status "
617 << loghex(status) << ", version " << loghex(version)
618 << ", manufacturer_name " << loghex(manufacturer_name)
619 << ", subversion " << loghex(subversion) << ", error " << ret;
620 }
621}
Jack He7d7a8de2019-01-20 21:31:12 -0800622
623void LogA2dpAudioUnderrunEvent(const RawAddress& address,
624 uint64_t encoding_interval_millis,
625 int num_missing_pcm_bytes) {
626 std::string obfuscated_id;
627 if (!address.IsEmpty()) {
628 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
629 }
630 // nullptr and size 0 represent missing value for obfuscated_id
631 android::util::BytesField bytes_field(
632 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
633 address.IsEmpty() ? 0 : obfuscated_id.size());
634 int64_t encoding_interval_nanos = encoding_interval_millis * 1000000;
635 int ret = android::util::stats_write(
636 android::util::BLUETOOTH_A2DP_AUDIO_UNDERRUN_REPORTED, bytes_field,
637 encoding_interval_nanos, num_missing_pcm_bytes);
638 if (ret < 0) {
639 LOG(WARNING) << __func__ << ": failed for " << address
640 << ", encoding_interval_nanos " << encoding_interval_nanos
641 << ", num_missing_pcm_bytes " << num_missing_pcm_bytes
642 << ", error " << ret;
643 }
644}
645
646void LogA2dpAudioOverrunEvent(const RawAddress& address,
647 uint64_t encoding_interval_millis,
648 int num_dropped_buffers,
649 int num_dropped_encoded_frames,
650 int num_dropped_encoded_bytes) {
651 std::string obfuscated_id;
652 if (!address.IsEmpty()) {
653 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
654 }
655 // nullptr and size 0 represent missing value for obfuscated_id
656 android::util::BytesField bytes_field(
657 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
658 address.IsEmpty() ? 0 : obfuscated_id.size());
659 int64_t encoding_interval_nanos = encoding_interval_millis * 1000000;
660 int ret = android::util::stats_write(
661 android::util::BLUETOOTH_A2DP_AUDIO_OVERRUN_REPORTED, bytes_field,
662 encoding_interval_nanos, num_dropped_buffers, num_dropped_encoded_frames,
663 num_dropped_encoded_bytes);
664 if (ret < 0) {
665 LOG(WARNING) << __func__ << ": failed to log for " << address
666 << ", encoding_interval_nanos " << encoding_interval_nanos
667 << ", num_dropped_buffers " << num_dropped_buffers
668 << ", num_dropped_encoded_frames "
669 << num_dropped_encoded_frames << ", num_dropped_encoded_bytes "
670 << num_dropped_encoded_bytes << ", error " << ret;
671 }
672}
673
674void LogReadRssiResult(const RawAddress& address, uint16_t handle,
675 uint32_t cmd_status, int8_t rssi) {
676 std::string obfuscated_id;
677 if (!address.IsEmpty()) {
678 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
679 }
680 // nullptr and size 0 represent missing value for obfuscated_id
681 android::util::BytesField bytes_field(
682 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
683 address.IsEmpty() ? 0 : obfuscated_id.size());
684 int ret =
685 android::util::stats_write(android::util::BLUETOOTH_DEVICE_RSSI_REPORTED,
686 bytes_field, handle, cmd_status, rssi);
687 if (ret < 0) {
688 LOG(WARNING) << __func__ << ": failed for " << address << ", handle "
689 << handle << ", status " << loghex(cmd_status) << ", rssi "
690 << rssi << " dBm, error " << ret;
691 }
692}
693
694void LogReadFailedContactCounterResult(const RawAddress& address,
695 uint16_t handle, uint32_t cmd_status,
696 int32_t failed_contact_counter) {
697 std::string obfuscated_id;
698 if (!address.IsEmpty()) {
699 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
700 }
701 // nullptr and size 0 represent missing value for obfuscated_id
702 android::util::BytesField bytes_field(
703 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
704 address.IsEmpty() ? 0 : obfuscated_id.size());
705 int ret = android::util::stats_write(
706 android::util::BLUETOOTH_DEVICE_FAILED_CONTACT_COUNTER_REPORTED,
707 bytes_field, handle, cmd_status, failed_contact_counter);
708 if (ret < 0) {
709 LOG(WARNING) << __func__ << ": failed for " << address << ", handle "
710 << handle << ", status " << loghex(cmd_status)
711 << ", failed_contact_counter " << failed_contact_counter
712 << " packets, error " << ret;
713 }
714}
715
716void LogReadTxPowerLevelResult(const RawAddress& address, uint16_t handle,
717 uint32_t cmd_status,
718 int32_t transmit_power_level) {
719 std::string obfuscated_id;
720 if (!address.IsEmpty()) {
721 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
722 }
723 // nullptr and size 0 represent missing value for obfuscated_id
724 android::util::BytesField bytes_field(
725 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
726 address.IsEmpty() ? 0 : obfuscated_id.size());
727 int ret = android::util::stats_write(
728 android::util::BLUETOOTH_DEVICE_TX_POWER_LEVEL_REPORTED, bytes_field,
729 handle, cmd_status, transmit_power_level);
730 if (ret < 0) {
731 LOG(WARNING) << __func__ << ": failed for " << address << ", handle "
732 << handle << ", status " << loghex(cmd_status)
733 << ", transmit_power_level " << transmit_power_level
734 << " packets, error " << ret;
735 }
736}
737
Jack Heb75275d2019-01-31 15:17:08 -0800738void LogSmpPairingEvent(const RawAddress& address, uint8_t smp_cmd,
739 android::bluetooth::DirectionEnum direction,
740 uint8_t smp_fail_reason) {
741 std::string obfuscated_id;
742 if (!address.IsEmpty()) {
743 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
744 }
745 // nullptr and size 0 represent missing value for obfuscated_id
746 android::util::BytesField obfuscated_id_field(
747 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
748 address.IsEmpty() ? 0 : obfuscated_id.size());
749 int ret = android::util::stats_write(
750 android::util::BLUETOOTH_SMP_PAIRING_EVENT_REPORTED, obfuscated_id_field,
751 smp_cmd, direction, smp_fail_reason);
752 if (ret < 0) {
753 LOG(WARNING) << __func__ << ": failed for " << address << ", smp_cmd "
754 << loghex(smp_cmd) << ", direction " << direction
755 << ", smp_fail_reason " << loghex(smp_fail_reason)
756 << ", error " << ret;
757 }
758}
759
Jack He0d888e52019-01-31 17:44:46 -0800760void LogClassicPairingEvent(const RawAddress& address, uint16_t handle,
761 uint32_t hci_cmd, uint16_t hci_event,
762 uint16_t cmd_status, uint16_t reason_code) {
763 std::string obfuscated_id;
764 if (!address.IsEmpty()) {
765 obfuscated_id = AddressObfuscator::GetInstance()->Obfuscate(address);
766 }
767 // nullptr and size 0 represent missing value for obfuscated_id
768 android::util::BytesField obfuscated_id_field(
769 address.IsEmpty() ? nullptr : obfuscated_id.c_str(),
770 address.IsEmpty() ? 0 : obfuscated_id.size());
771 int ret = android::util::stats_write(
772 android::util::BLUETOOTH_CLASSIC_PAIRING_EVENT_REPORTED,
773 obfuscated_id_field, handle, hci_cmd, hci_event, cmd_status, reason_code);
774 if (ret < 0) {
775 LOG(WARNING) << __func__ << ": failed for " << address << ", handle "
776 << handle << ", hci_cmd " << loghex(hci_cmd) << ", hci_event "
777 << loghex(hci_event) << ", cmd_status " << loghex(cmd_status)
778 << ", reason " << loghex(reason_code) << ", error " << ret;
779 }
780}
781
Jack He42823982018-08-15 12:38:37 -0700782} // namespace common
783
784} // namespace bluetooth