1 /*
2 * Copyright 2023 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #define LOG_TAG "stack_power_tel"
18
19 #include "osi/include/stack_power_telemetry.h"
20
21 #include <bluetooth/log.h>
22 #include <com_android_bluetooth_flags.h>
23 #include <sys/stat.h>
24 #include <time.h>
25
26 #include <atomic>
27 #include <list>
28 #include <map>
29 #include <mutex>
30
31 #include "osi/include/properties.h"
32 #include "stack/include/acl_api_types.h"
33 #include "stack/include/bt_psm_types.h"
34 #include "stack/include/btm_status.h"
35 #include "types/raw_address.h"
36
37 using namespace bluetooth;
38
get_current_time()39 static time_t get_current_time() { return time(0); }
40
41 namespace {
42
43 constexpr int64_t kTrafficLogTime = 120; // 120seconds
44 constexpr uint8_t kLogEntriesSize{15};
45 constexpr std::string_view kLogPerChannelProperty =
46 "bluetooth.powertelemetry.log_per_channel.enabled";
47 constexpr std::string_view kPowerTelemetryEnabledProperty = "bluetooth.powertelemetry.enabled";
48 bool power_telemerty_enabled_ = false;
49
GetTimeString(time_t tstamp)50 std::string GetTimeString(time_t tstamp) {
51 char buffer[15];
52 tm* nTm = localtime(&tstamp);
53 strftime(buffer, 15, "%m-%d %H:%M:%S", nTm);
54 return std::string(buffer);
55 }
56
57 enum class State {
58 kDisconnected = 0,
59 kConnected = 1,
60 };
61
62 enum class ChannelType {
63 kUnknown = 0,
64 kRfcomm = 1,
65 kL2cap = 2,
66 };
67
PsmToChannelType(const uint16_t & psm)68 ChannelType PsmToChannelType(const uint16_t& psm) {
69 switch (psm) {
70 case BT_PSM_RFCOMM:
71 return ChannelType::kRfcomm;
72 break;
73 }
74 return ChannelType::kL2cap;
75 }
76
77 struct Duration {
78 time_t begin = 0;
79 time_t end = 0;
80 };
81
82 struct DataTransfer {
83 struct {
84 int64_t bytes{0};
85 } rx, tx;
86 };
87
88 struct LinkDetails {
89 RawAddress bd_addr = RawAddress::kEmpty;
90 uint16_t handle = 0;
91 Duration duration;
92 uint8_t tx_power_level = 0;
93 };
94
95 struct ChannelDetails {
96 RawAddress bd_addr = RawAddress::kEmpty;
97 int32_t psm = 0;
98 struct {
99 uint16_t cid = 0;
100 } src, dst;
101 State state = State::kDisconnected;
102 ChannelType channel_type = ChannelType::kUnknown;
103 DataTransfer data_transfer;
104 Duration duration;
105 struct {
106 time_t last_data_sent = 0;
107 } rx, tx;
108 };
109
110 struct AclPacketDetails {
111 struct {
112 uint32_t pkt_count = 0;
113 int64_t byte_count = 0;
114 } rx, tx;
115 };
116
117 struct AdvDetails {
118 Duration active;
119 };
120
121 struct ScanDetails {
122 int32_t count = 0;
123 };
124
125 struct SniffData {
126 RawAddress bd_addr = RawAddress::kEmpty;
127 uint32_t sniff_count = 0, active_count = 0;
128 time_t sniff_duration_ts = 0, active_duration_ts = 0;
129 time_t last_mode_change_ts = get_current_time();
130 };
131
132 class LogDataContainer {
133 public:
134 struct Duration lifetime;
135 std::map<RawAddress, std::list<ChannelDetails>> channel_map;
136 DataTransfer l2c_data, rfc_data;
137 std::map<uint16_t, SniffData> sniff_activity_map;
138 struct {
139 std::map<uint16_t, LinkDetails> link_details_map;
140 std::list<LinkDetails> link_details_list;
141 } acl, sco;
142 std::list<AdvDetails> adv_list;
143 ScanDetails scan_details, inq_scan_details, le_scan_details;
144 AclPacketDetails acl_pkt_ds, hci_cmd_evt_ds;
145 };
146
147 } // namespace
148
149 struct power_telemetry::PowerTelemetryImpl {
PowerTelemetryImplpower_telemetry::PowerTelemetryImpl150 PowerTelemetryImpl() {
151 idx_containers = 0;
152 traffic_logged_ts_ = get_current_time();
153 log_per_channel_ = osi_property_get_bool(std::string(kLogPerChannelProperty).c_str(), false);
154 power_telemetry_enabled_property_ =
155 osi_property_get_bool(std::string(kPowerTelemetryEnabledProperty).c_str(), true);
156
157 // Enable this feature when both feature flag and sysprops turn on.
158 power_telemerty_enabled_ = com::android::bluetooth::flags::bluetooth_power_telemetry() &&
159 power_telemetry_enabled_property_;
160 }
161
GetCurrentLogDataContainerpower_telemetry::PowerTelemetryImpl162 LogDataContainer& GetCurrentLogDataContainer() { return log_data_containers_[idx_containers]; }
163
maybe_log_datapower_telemetry::PowerTelemetryImpl164 void maybe_log_data() {
165 if ((get_current_time() - traffic_logged_ts_) >= kTrafficLogTime) {
166 LogDataTransfer();
167 }
168 }
169
170 void LogDataTransfer();
171 void RecordLogDataContainer();
172
173 mutable std::mutex dumpsys_mutex_;
174 LogDataContainer log_data_containers_[kLogEntriesSize];
175 std::atomic_int idx_containers;
176 time_t traffic_logged_ts_ = 0;
177 struct {
178 struct {
179 int64_t bytes_ = 0;
180 } rx, tx;
181 } l2c, rfc;
182 struct {
183 uint32_t pkt_ = 0;
184 int64_t len_ = 0;
185 } rx, tx;
186
187 struct {
188 uint16_t count_ = 0;
189 } scan, inq_scan, ble_adv, ble_scan;
190
191 struct {
192 uint32_t count_ = 0;
193 } cmd, event;
194 bool scan_timer_started_ = false;
195 bool log_per_channel_ = false;
196 bool power_telemetry_enabled_property_ = false;
197 };
198
LogDataTransfer()199 void power_telemetry::PowerTelemetryImpl::LogDataTransfer() {
200 if (!power_telemerty_enabled_) {
201 return;
202 }
203
204 LogDataContainer& ldc = GetCurrentLogDataContainer();
205
206 if ((l2c.rx.bytes_ != 0) || (l2c.tx.bytes_ != 0)) {
207 ldc.l2c_data = {
208 .rx =
209 {
210 .bytes = l2c.rx.bytes_,
211 },
212 .tx =
213 {
214 .bytes = l2c.tx.bytes_,
215 },
216 };
217 l2c = {};
218 }
219
220 if ((rfc.rx.bytes_ != 0) || (rfc.tx.bytes_ != 0)) {
221 ldc.rfc_data = {
222 .rx =
223 {
224 .bytes = rfc.rx.bytes_,
225 },
226 .tx =
227 {
228 .bytes = rfc.tx.bytes_,
229 },
230 };
231 rfc = {};
232 }
233
234 if (scan.count_ != 0) {
235 ldc.scan_details = {
236 .count = scan.count_,
237 };
238 scan.count_ = 0;
239 }
240
241 if (inq_scan.count_ != 0) {
242 ldc.inq_scan_details = {
243 .count = inq_scan.count_,
244 };
245 inq_scan.count_ = 0;
246 }
247
248 if ((rx.pkt_ != 0) || (tx.pkt_ != 0)) {
249 ldc.acl_pkt_ds = {
250 .rx =
251 {
252 .pkt_count = rx.pkt_,
253 .byte_count = rx.len_,
254 },
255 .tx =
256 {
257 .pkt_count = tx.pkt_,
258 .byte_count = tx.len_,
259 },
260 };
261 rx.pkt_ = tx.pkt_ = rx.len_ = tx.len_ = 0;
262 }
263
264 if ((cmd.count_ != 0) || (event.count_ != 0)) {
265 ldc.hci_cmd_evt_ds = {
266 .rx =
267 {
268 .pkt_count = event.count_,
269 },
270 .tx =
271 {
272 .pkt_count = cmd.count_,
273 },
274 };
275 cmd.count_ = event.count_ = 0;
276 }
277
278 if (ble_scan.count_ != 0) {
279 ldc.le_scan_details = {
280 .count = ble_scan.count_,
281 };
282 ble_scan.count_ = 0;
283 }
284
285 ldc.lifetime.begin = traffic_logged_ts_;
286 ldc.lifetime.end = get_current_time();
287
288 traffic_logged_ts_ = get_current_time();
289 RecordLogDataContainer();
290 }
291
RecordLogDataContainer()292 void power_telemetry::PowerTelemetryImpl::RecordLogDataContainer() {
293 if (!power_telemerty_enabled_) {
294 return;
295 }
296
297 LogDataContainer& ldc = GetCurrentLogDataContainer();
298
299 log::info(
300 "bt_power: scan: {}, inqScan: {}, aclTx: {}, aclRx: {}, hciCmd: {}, "
301 "hciEvt: {}, bleScan: {}",
302 ldc.scan_details.count, ldc.inq_scan_details.count, ldc.acl_pkt_ds.tx.pkt_count,
303 ldc.acl_pkt_ds.rx.pkt_count, ldc.hci_cmd_evt_ds.tx.pkt_count,
304 ldc.hci_cmd_evt_ds.rx.pkt_count, ldc.le_scan_details.count);
305
306 idx_containers++;
307 if (idx_containers >= kLogEntriesSize) {
308 idx_containers = 0;
309 }
310
311 log_data_containers_[idx_containers] = LogDataContainer();
312 }
313
GetInstance()314 power_telemetry::PowerTelemetry& power_telemetry::GetInstance() {
315 static power_telemetry::PowerTelemetry power_telemetry;
316 return power_telemetry;
317 }
318
PowerTelemetry()319 power_telemetry::PowerTelemetry::PowerTelemetry() {
320 pimpl_ = std::make_unique<PowerTelemetryImpl>();
321 }
322
LogInqScanStarted()323 void power_telemetry::PowerTelemetry::LogInqScanStarted() {
324 if (!power_telemerty_enabled_) {
325 return;
326 }
327
328 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
329 pimpl_->inq_scan.count_++;
330 pimpl_->maybe_log_data();
331 }
332
LogInqScanStopped()333 void power_telemetry::PowerTelemetry::LogInqScanStopped() {
334 if (!power_telemerty_enabled_) {
335 return;
336 }
337
338 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
339 pimpl_->maybe_log_data();
340 }
341
LogBleScan(uint16_t num_resps)342 void power_telemetry::PowerTelemetry::LogBleScan(uint16_t num_resps) {
343 if (!power_telemerty_enabled_) {
344 return;
345 }
346
347 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
348 pimpl_->ble_scan.count_ += num_resps;
349 pimpl_->maybe_log_data();
350 }
351
LogBleAdvStarted()352 void power_telemetry::PowerTelemetry::LogBleAdvStarted() {
353 if (!power_telemerty_enabled_) {
354 return;
355 }
356
357 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
358 const time_t current_time = get_current_time();
359 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
360 ldc.adv_list.emplace_back(AdvDetails{.active.begin = current_time});
361 }
362
LogBleAdvStopped()363 void power_telemetry::PowerTelemetry::LogBleAdvStopped() {
364 if (!power_telemerty_enabled_) {
365 return;
366 }
367
368 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
369 const time_t current_time = get_current_time();
370
371 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
372 if (ldc.adv_list.size() == 0) {
373 log::warn("Empty advList. Skip LogBleAdvDetails.");
374 return;
375 }
376 ldc.adv_list.back().active.end = current_time;
377 }
378
LogTxPower(void * res)379 void power_telemetry::PowerTelemetry::LogTxPower(void* res) {
380 if (!power_telemerty_enabled_) {
381 return;
382 }
383
384 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
385 tBTM_TX_POWER_RESULT* result = (tBTM_TX_POWER_RESULT*)res;
386 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
387
388 if (result->status != tBTM_STATUS::BTM_SUCCESS) {
389 return;
390 }
391
392 for (auto it : ldc.acl.link_details_map) {
393 uint16_t handle = it.first;
394 LinkDetails lds = it.second;
395 if (lds.bd_addr == result->rem_bda) {
396 lds.tx_power_level = result->tx_power;
397 ldc.acl.link_details_map[handle] = lds;
398 break;
399 }
400 }
401 pimpl_->maybe_log_data();
402 }
403
LogLinkDetails(uint16_t handle,const RawAddress & bd_addr,bool is_connected,bool is_acl_link)404 void power_telemetry::PowerTelemetry::LogLinkDetails(uint16_t handle, const RawAddress& bd_addr,
405 bool is_connected, bool is_acl_link) {
406 if (!power_telemerty_enabled_) {
407 return;
408 }
409
410 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
411 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
412 std::map<uint16_t, LinkDetails>& link_map =
413 is_acl_link ? ldc.acl.link_details_map : ldc.sco.link_details_map;
414 std::list<LinkDetails>& link_list =
415 is_acl_link ? ldc.acl.link_details_list : ldc.sco.link_details_list;
416
417 if (is_connected == false && link_map.count(handle) != 0) {
418 LinkDetails link_details = link_map[handle];
419 link_details.duration.end = get_current_time();
420 link_list.push_back(link_details);
421 link_map.erase(handle);
422 } else if (is_connected == true) {
423 link_map[handle] = {
424 .bd_addr = bd_addr,
425 .handle = handle,
426 .duration.begin = get_current_time(),
427 .tx_power_level = 0,
428 };
429
430 if (is_acl_link) {
431 SniffData sniff_data;
432 if (ldc.sniff_activity_map.count(handle) != 0) {
433 ldc.sniff_activity_map.erase(handle);
434 }
435 sniff_data.bd_addr = bd_addr;
436 sniff_data.active_count = 1;
437 sniff_data.last_mode_change_ts = get_current_time();
438 ldc.sniff_activity_map[handle] = sniff_data;
439 }
440 }
441
442 pimpl_->maybe_log_data();
443 }
444
LogHciCmdDetail()445 void power_telemetry::PowerTelemetry::LogHciCmdDetail() {
446 if (!power_telemerty_enabled_) {
447 return;
448 }
449
450 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
451 pimpl_->cmd.count_++;
452 pimpl_->maybe_log_data();
453 }
454
LogHciEvtDetail()455 void power_telemetry::PowerTelemetry::LogHciEvtDetail() {
456 if (!power_telemerty_enabled_) {
457 return;
458 }
459
460 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
461 pimpl_->event.count_++;
462 pimpl_->maybe_log_data();
463 }
464
LogSniffStarted(uint16_t handle,const RawAddress & bd_addr)465 void power_telemetry::PowerTelemetry::LogSniffStarted(uint16_t handle, const RawAddress& bd_addr) {
466 if (!power_telemerty_enabled_) {
467 return;
468 }
469
470 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
471 const time_t current_timestamp = get_current_time();
472 SniffData sniff_data;
473 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
474 if (ldc.sniff_activity_map.count(handle) == 0) {
475 sniff_data.bd_addr = bd_addr;
476 } else {
477 sniff_data = ldc.sniff_activity_map[handle];
478 }
479 sniff_data.sniff_count++;
480 sniff_data.active_duration_ts += current_timestamp - sniff_data.last_mode_change_ts;
481 sniff_data.last_mode_change_ts = get_current_time();
482 ldc.sniff_activity_map[handle] = sniff_data;
483
484 pimpl_->maybe_log_data();
485 }
486
LogSniffStopped(uint16_t handle,const RawAddress & bd_addr)487 void power_telemetry::PowerTelemetry::LogSniffStopped(uint16_t handle, const RawAddress& bd_addr) {
488 if (!power_telemerty_enabled_) {
489 return;
490 }
491
492 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
493 const time_t current_timestamp = get_current_time();
494 SniffData sniff_data;
495 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
496 if (ldc.sniff_activity_map.count(handle) == 0) {
497 sniff_data.bd_addr = bd_addr;
498 } else {
499 sniff_data = ldc.sniff_activity_map[handle];
500 }
501 sniff_data.active_count++;
502 sniff_data.sniff_duration_ts += current_timestamp - sniff_data.last_mode_change_ts;
503 sniff_data.last_mode_change_ts = get_current_time();
504 ldc.sniff_activity_map[handle] = sniff_data;
505
506 pimpl_->maybe_log_data();
507 }
508
LogScanStarted()509 void power_telemetry::PowerTelemetry::LogScanStarted() {
510 if (!power_telemerty_enabled_) {
511 return;
512 }
513
514 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
515 pimpl_->scan.count_++;
516 pimpl_->maybe_log_data();
517 }
518
LogTxAclPktData(uint16_t len)519 void power_telemetry::PowerTelemetry::LogTxAclPktData(uint16_t len) {
520 if (!power_telemerty_enabled_) {
521 return;
522 }
523
524 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
525 pimpl_->tx.pkt_++;
526 pimpl_->tx.len_ += len;
527 pimpl_->maybe_log_data();
528 }
529
LogRxAclPktData(uint16_t len)530 void power_telemetry::PowerTelemetry::LogRxAclPktData(uint16_t len) {
531 if (!power_telemerty_enabled_) {
532 return;
533 }
534
535 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
536 pimpl_->rx.pkt_++;
537 pimpl_->rx.len_ += len;
538 pimpl_->maybe_log_data();
539 }
540
LogChannelConnected(uint16_t psm,int32_t src_id,int32_t dst_id,const RawAddress & bd_addr)541 void power_telemetry::PowerTelemetry::LogChannelConnected(uint16_t psm, int32_t src_id,
542 int32_t dst_id,
543 const RawAddress& bd_addr) {
544 if (!power_telemerty_enabled_) {
545 return;
546 }
547
548 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
549 std::list<ChannelDetails> channel_details_list;
550 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
551 const ChannelType channel_type = PsmToChannelType(psm);
552 ChannelDetails channel_details = {
553 .bd_addr = bd_addr,
554 .psm = psm,
555 .src.cid = static_cast<uint16_t>(src_id),
556 .dst.cid = static_cast<uint16_t>(dst_id),
557 .state = State::kConnected,
558 .channel_type = channel_type,
559 .data_transfer = {},
560 .duration.begin = get_current_time(),
561 .rx = {},
562 .tx = {},
563 };
564
565 if (ldc.channel_map.count(bd_addr) == 0) {
566 ldc.channel_map.insert(std::pair<RawAddress, std::list<ChannelDetails>>(
567 bd_addr, std::list<ChannelDetails>({channel_details})));
568 } else {
569 ldc.channel_map[bd_addr].emplace_back(channel_details);
570 }
571
572 pimpl_->maybe_log_data();
573 }
574
LogChannelDisconnected(uint16_t psm,int32_t src_id,int32_t dst_id,const RawAddress & bd_addr)575 void power_telemetry::PowerTelemetry::LogChannelDisconnected(uint16_t psm, int32_t src_id,
576 int32_t dst_id,
577 const RawAddress& bd_addr) {
578 if (!power_telemerty_enabled_) {
579 return;
580 }
581
582 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
583 std::list<ChannelDetails> channel_details_list;
584 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
585 if (ldc.channel_map.count(bd_addr) == 0) {
586 return;
587 }
588
589 const ChannelType channel_type = PsmToChannelType(psm);
590
591 for (auto& channel_detail : ldc.channel_map[bd_addr]) {
592 if (channel_detail.src.cid == src_id && channel_detail.dst.cid == dst_id &&
593 channel_detail.channel_type == channel_type) {
594 channel_detail.state = State::kDisconnected;
595 channel_detail.duration.end = get_current_time();
596 break;
597 }
598 }
599
600 pimpl_->maybe_log_data();
601 }
602
LogTxBytes(uint16_t psm,int32_t src_id,int32_t dst_id,const RawAddress & bd_addr,int32_t num_bytes)603 void power_telemetry::PowerTelemetry::LogTxBytes(uint16_t psm, int32_t src_id, int32_t dst_id,
604 const RawAddress& bd_addr, int32_t num_bytes) {
605 if (!power_telemerty_enabled_) {
606 return;
607 }
608
609 const ChannelType channel_type = PsmToChannelType(psm);
610 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
611 if (pimpl_->log_per_channel_ == true) {
612 std::list<ChannelDetails> channel_details_list;
613 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
614 if (ldc.channel_map.count(bd_addr) == 0) {
615 return;
616 }
617
618 for (auto& channel_details : ldc.channel_map[bd_addr]) {
619 if (channel_details.src.cid == src_id && channel_details.dst.cid == dst_id &&
620 channel_details.channel_type == channel_type) {
621 channel_details.data_transfer.tx.bytes += num_bytes;
622 channel_details.tx.last_data_sent = get_current_time();
623 break;
624 }
625 }
626 }
627 if (channel_type == ChannelType::kRfcomm) {
628 pimpl_->rfc.tx.bytes_ += num_bytes;
629 } else {
630 pimpl_->l2c.tx.bytes_ += num_bytes;
631 }
632 pimpl_->maybe_log_data();
633 }
634
LogRxBytes(uint16_t psm,int32_t src_id,int32_t dst_id,const RawAddress & bd_addr,int32_t num_bytes)635 void power_telemetry::PowerTelemetry::LogRxBytes(uint16_t psm, int32_t src_id, int32_t dst_id,
636 const RawAddress& bd_addr, int32_t num_bytes) {
637 if (!power_telemerty_enabled_) {
638 return;
639 }
640
641 const ChannelType channel_type = PsmToChannelType(psm);
642 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
643 if (pimpl_->log_per_channel_ == true) {
644 std::list<ChannelDetails> channel_details_list;
645 LogDataContainer& ldc = pimpl_->GetCurrentLogDataContainer();
646 if (ldc.channel_map.count(bd_addr) == 0) {
647 return;
648 }
649
650 for (auto& channel_detail : ldc.channel_map[bd_addr]) {
651 if (channel_detail.src.cid == src_id && channel_detail.dst.cid == dst_id &&
652 channel_detail.channel_type == channel_type) {
653 channel_detail.data_transfer.rx.bytes += num_bytes;
654 channel_detail.rx.last_data_sent = get_current_time();
655 break;
656 }
657 }
658 }
659
660 switch (channel_type) {
661 case ChannelType::kRfcomm:
662 pimpl_->rfc.rx.bytes_ += num_bytes;
663 break;
664 case ChannelType::kL2cap:
665 pimpl_->l2c.rx.bytes_ += num_bytes;
666 break;
667 case ChannelType::kUnknown:
668 break;
669 }
670
671 pimpl_->maybe_log_data();
672 }
673
Dumpsys(int32_t fd)674 void power_telemetry::PowerTelemetry::Dumpsys(int32_t fd) {
675 if (!power_telemerty_enabled_) {
676 return;
677 }
678
679 std::lock_guard<std::mutex> lock(pimpl_->dumpsys_mutex_);
680 pimpl_->RecordLogDataContainer();
681
682 dprintf(fd, "\nPower Telemetry Data:\n");
683 dprintf(fd, "\nBR/EDR Scan Events:\n");
684 dprintf(fd, "%-22s %-22s %-15s\n", "StartTimeStamp", "EndTimeStamp", "Number of Scans");
685 for (auto&& ldc : pimpl_->log_data_containers_) {
686 if (ldc.scan_details.count == 0) {
687 continue;
688 }
689 dprintf(fd, "%-22s %-22s %-15d\n", GetTimeString(ldc.lifetime.begin).c_str(),
690 GetTimeString(ldc.lifetime.end).c_str(), ldc.scan_details.count);
691 }
692 dprintf(fd, "\nBR/EDR InqScan Events:\n");
693 dprintf(fd, "%-22s %-22s %-15s\n", "StartTimeStamp", "EndTimeStamp", "Number of InqScans");
694 for (auto&& ldc : pimpl_->log_data_containers_) {
695 if (ldc.inq_scan_details.count == 0) {
696 continue;
697 }
698 dprintf(fd, "%-22s %-22s %-15d\n", GetTimeString(ldc.lifetime.begin).c_str(),
699 GetTimeString(ldc.lifetime.end).c_str(), ldc.inq_scan_details.count);
700 }
701
702 dprintf(fd, "\nACL Packet Details:\n");
703 dprintf(fd, "%-22s %-22s %-12s %-12s %-12s %-12s\n", "StartTimeStamp", "EndTimeStamp",
704 "Tx Packets", "Tx Bytes", "Rx Packets", "Rx Bytes");
705 for (auto&& ldc : pimpl_->log_data_containers_) {
706 if ((ldc.acl_pkt_ds.tx.byte_count == 0) && (ldc.acl_pkt_ds.rx.byte_count == 0)) {
707 continue;
708 }
709 dprintf(fd, "%-22s %-22s %-12d %-12ld %-12d %-12ld\n",
710 GetTimeString(ldc.lifetime.begin).c_str(), GetTimeString(ldc.lifetime.end).c_str(),
711 ldc.acl_pkt_ds.tx.pkt_count, (long)ldc.acl_pkt_ds.tx.byte_count,
712 ldc.acl_pkt_ds.rx.pkt_count, (long)ldc.acl_pkt_ds.rx.byte_count);
713 }
714
715 dprintf(fd, "\nHCI CMD/EVT Details:\n");
716 dprintf(fd, "%-22s %-22s %-14s %-14s\n", "StartTimeStamp", "EndTimeStamp", "HCI Commands",
717 "HCI Events");
718 for (auto&& ldc : pimpl_->log_data_containers_) {
719 if ((ldc.hci_cmd_evt_ds.tx.pkt_count == 0) && (ldc.hci_cmd_evt_ds.rx.pkt_count == 0)) {
720 continue;
721 }
722 dprintf(fd, "%-22s %-22s %-14d %-14d\n", GetTimeString(ldc.lifetime.begin).c_str(),
723 GetTimeString(ldc.lifetime.end).c_str(), ldc.hci_cmd_evt_ds.tx.pkt_count,
724 ldc.hci_cmd_evt_ds.rx.pkt_count);
725 }
726 dprintf(fd, "\nBLE Scan Details:\n");
727 dprintf(fd, "%-22s %-22s %-14s\n", "StartTimeStamp", "EndTimeStamp", "Number of scans");
728 for (auto&& ldc : pimpl_->log_data_containers_) {
729 if (ldc.le_scan_details.count == 0) {
730 continue;
731 }
732 dprintf(fd, "%-22s %-22s %-14d\n", GetTimeString(ldc.lifetime.begin).c_str(),
733 GetTimeString(ldc.lifetime.end).c_str(), ldc.le_scan_details.count);
734 }
735 dprintf(fd, "\nL2CAP/RFCOMM Channel Events:\n");
736 dprintf(fd, "%-19s %-7s %-7s %-7s %-8s %-22s", "RemoteAddress", "Type", "SrcId", "DstId", "PSM",
737 "ConnectedTimeStamp");
738 dprintf(fd, " %-22s %-14s ", "DisconnectedTimeStamp", "State");
739 if (pimpl_->log_per_channel_ == true) {
740 dprintf(fd, " %-10s %-10s %-22s %-22s", "TxBytes", "RxBytes", "LastTxTimeStamp",
741 "LastRxTimeStamp");
742 }
743 dprintf(fd, "\n");
744 for (auto&& ldc : pimpl_->log_data_containers_) {
745 for (auto& itr : ldc.channel_map) {
746 const RawAddress& bd_addr = itr.first;
747 std::list<ChannelDetails> channel_details_list = itr.second;
748 for (auto& channel_details : channel_details_list) {
749 dprintf(fd, "%-19s ", bd_addr.ToRedactedStringForLogging().c_str());
750 dprintf(fd, "%-7s %-7d %-7d %-8d %-22s %-22s %-14s",
751 (channel_details.channel_type == ChannelType::kRfcomm) ? "RFCOMM" : "L2CAP",
752 channel_details.src.cid, channel_details.dst.cid, channel_details.psm,
753 GetTimeString(channel_details.duration.begin).c_str(),
754 GetTimeString(channel_details.duration.end).c_str(),
755 (channel_details.state == State::kDisconnected) ? "DISCONNECTED" : "CONNECTED");
756 if (pimpl_->log_per_channel_ == true) {
757 dprintf(fd, "%-10ld %-10ld %-22s %-22s", (long)channel_details.data_transfer.tx.bytes,
758 (long)channel_details.data_transfer.rx.bytes,
759 GetTimeString(channel_details.tx.last_data_sent).c_str(),
760 GetTimeString(channel_details.rx.last_data_sent).c_str());
761 }
762 dprintf(fd, "\n");
763 }
764 }
765 }
766
767 dprintf(fd, "\n\nBluetooth Data Traffic Details\n");
768 dprintf(fd, "L2cap Data Traffic\n");
769 dprintf(fd, "%-22s %-22s %-10s %-10s\n", "StartTime", "EndTime", "TxBytes", "RxBytes");
770 for (auto&& ldc : pimpl_->log_data_containers_) {
771 if (ldc.l2c_data.tx.bytes == 0 && ldc.l2c_data.rx.bytes) {
772 continue;
773 }
774 dprintf(fd, "%-22s %-22s %-10ld %-10ld\n", GetTimeString(ldc.lifetime.begin).c_str(),
775 GetTimeString(ldc.lifetime.end).c_str(), (long)ldc.l2c_data.tx.bytes,
776 (long)ldc.l2c_data.rx.bytes);
777 }
778
779 dprintf(fd, "\nRfcomm Data Traffic\n");
780 dprintf(fd, "%-22s %-22s %-10s %-10s\n", "StartTime", "EndTime", "TxBytes", "RxBytes");
781 for (auto&& ldc : pimpl_->log_data_containers_) {
782 if (ldc.rfc_data.tx.bytes == 0 && ldc.rfc_data.rx.bytes == 0) {
783 continue;
784 }
785 dprintf(fd, "%-22s %-22s %-10ld %-10ld\n", GetTimeString(ldc.lifetime.begin).c_str(),
786 GetTimeString(ldc.lifetime.end).c_str(), (long)ldc.rfc_data.tx.bytes,
787 (long)ldc.rfc_data.rx.bytes);
788 }
789
790 dprintf(fd, "\n\nSniff Activity Details\n");
791 dprintf(fd, "%-8s %-19s %-19s %-24s %-19s %-24s\n", "Handle", "BDADDR", "ActiveModeCount",
792 "ActiveModeDuration(sec)", "SniffModeCount", "SniffModeDuration(sec)");
793 for (auto&& ldc : pimpl_->log_data_containers_) {
794 for (auto itr : ldc.sniff_activity_map) {
795 uint16_t handle = itr.first;
796 SniffData sniff_data = itr.second;
797 dprintf(fd, "%-8d %-19s %-19d %-24ld %-19d %-24ld\n", handle,
798 sniff_data.bd_addr.ToRedactedStringForLogging().c_str(), sniff_data.active_count,
799 (long)sniff_data.active_duration_ts, sniff_data.sniff_count,
800 (long)sniff_data.sniff_duration_ts);
801 }
802 }
803
804 dprintf(fd, "\n\nACL Link Details\n");
805 dprintf(fd, "%-6s %-19s %-22s %-22s %-8s\n", "handle", "BDADDR", "ConnectedTimeStamp",
806 "DisconnectedTimeStamp", "TxPower");
807 for (auto&& ldc : pimpl_->log_data_containers_) {
808 for (auto it : ldc.acl.link_details_map) {
809 uint16_t handle = it.first;
810 LinkDetails lds = it.second;
811 dprintf(fd, "%-6d %-19s %-22s %-22s %-8d\n", handle,
812 lds.bd_addr.ToRedactedStringForLogging().c_str(),
813 GetTimeString(lds.duration.begin).c_str(), GetTimeString(lds.duration.end).c_str(),
814 lds.tx_power_level);
815 }
816
817 for (auto& it : ldc.acl.link_details_list) {
818 dprintf(fd, "%-6d %-19s %-22s %-22s %-8d\n", it.handle,
819 it.bd_addr.ToRedactedStringForLogging().c_str(),
820 GetTimeString(it.duration.begin).c_str(), GetTimeString(it.duration.end).c_str(),
821 it.tx_power_level);
822 }
823 }
824 dprintf(fd, "\nSCO Link Details\n");
825 dprintf(fd, "%-6s %-19s %-22s %-22s\n", "handle", "BDADDR", "ConnectedTimeStamp",
826 "DisconnectedTimeStamp");
827 for (auto&& ldc : pimpl_->log_data_containers_) {
828 for (auto& it : ldc.sco.link_details_list) {
829 dprintf(fd, "%-6d %-19s %-22s %-22s\n", it.handle,
830 it.bd_addr.ToRedactedStringForLogging().c_str(),
831 GetTimeString(it.duration.begin).c_str(), GetTimeString(it.duration.end).c_str());
832 }
833 }
834
835 dprintf(fd, "\n\n");
836 }
837