Use proper API main/shim/acl::BTM_LogHistory

Towards loggable code

Bug: 163134718
Tag: #refactor
Test: gd/cert/run

Change-Id: Iab4c4278a02e2d0dff4f4e40a18911dee2620c5b

diff --git a/main/shim/acl.cc b/main/shim/acl.cc
index 2caf98a..4f89bb8 100644 (file)
--- a/main/shim/acl.cc
+++ b/main/shim/acl.cc
@@ -17,6 +17,7 @@
 #include "main/shim/acl.h"
 
 #include <base/location.h>
+#include <base/strings/stringprintf.h>
 
 #include <time.h>
 #include <chrono>
@@ -62,6 +63,7 @@ using HciHandle = uint16_t;
 using PageNumber = uint8_t;
 
 constexpr PageNumber kRemoteExtendedFeaturesPageZero = 0;
+constexpr char kBtmLogTag[] = "ACL";
 
 using SendDataUpwards = void (*const)(BT_HDR*);
 using OnDisconnect = std::function<void(HciHandle, hci::ErrorCode reason)>;
@@ -324,9 +326,10 @@ class ClassicShimAclConnection
                         ToLegacyHciErrorCode(hci::ErrorCode::SUCCESS),
                         ToRawAddress(connection_->GetAddress()),
                         ToLegacyRole(new_role));
-    btm_cb.history_->Push("%-32s: %s classic new_role:%s", "Role change",
-                          PRIVATE_ADDRESS(connection_->GetAddress()),
-                          hci::RoleText(new_role).c_str());
+    BTM_LogHistory(kBtmLogTag, ToRawAddress(connection_->GetAddress()),
+                   "Role change",
+                   base::StringPrintf("classic new_role:%s",
+                                      hci::RoleText(new_role).c_str()));
   }
 
   void OnDisconnection(hci::ErrorCode reason) override {
@@ -674,8 +677,8 @@ void bluetooth::shim::legacy::Acl::CreateClassicConnection(
   GetAclManager()->CreateConnection(address);
   LOG_DEBUG("Connection initiated for classic to remote:%s",
             PRIVATE_ADDRESS(address));
-  btm_cb.history_->Push("%-32s: %s classic", "Initiated connection",
-                        PRIVATE_ADDRESS(address));
+  BTM_LogHistory(kBtmLogTag, ToRawAddress(address), "Initiated connection",
+                 "classic");
 }
 
 void bluetooth::shim::legacy::Acl::CreateLeConnection(
@@ -683,8 +686,8 @@ void bluetooth::shim::legacy::Acl::CreateLeConnection(
   GetAclManager()->CreateLeConnection(address_with_type);
   LOG_DEBUG("Connection initiated for le connection to remote:%s",
             PRIVATE_ADDRESS(address_with_type));
-  btm_cb.history_->Push("%-32s: %s le", "Initiated connection",
-                        PRIVATE_ADDRESS(address_with_type));
+  BTM_LogHistory(kBtmLogTag, ToLegacyAddressWithType(address_with_type),
+                 "Initiated connection", "le");
 }
 
 void bluetooth::shim::legacy::Acl::CancelLeConnection(
@@ -692,8 +695,8 @@ void bluetooth::shim::legacy::Acl::CancelLeConnection(
   GetAclManager()->CancelLeConnect(address_with_type);
   LOG_DEBUG("Cancelled le connection to remote:%s",
             PRIVATE_ADDRESS(address_with_type));
-  btm_cb.history_->Push("%-32s: %s le", "Cancelled connection",
-                        PRIVATE_ADDRESS(address_with_type));
+  BTM_LogHistory(kBtmLogTag, ToLegacyAddressWithType(address_with_type),
+                 "Cancelled connection", "le");
 }
 
 void bluetooth::shim::legacy::Acl::OnClassicLinkDisconnected(
@@ -707,9 +710,9 @@ void bluetooth::shim::legacy::Acl::OnClassicLinkDisconnected(
   LOG_DEBUG("Disconnected classic link remote:%s handle:%hu reason:%s",
             PRIVATE_ADDRESS(remote_address), handle,
             ErrorCodeText(reason).c_str());
-  btm_cb.history_->Push("%-32s: %s classic reason:%s", "Disconnected",
-                        PRIVATE_ADDRESS(remote_address),
-                        ErrorCodeText(reason).c_str());
+  BTM_LogHistory(
+      kBtmLogTag, ToRawAddress(remote_address), "Disconnected",
+      base::StringPrintf("classic reason:%s", ErrorCodeText(reason).c_str()));
 }
 
 void bluetooth::shim::legacy::Acl::OnLeLinkDisconnected(HciHandle handle,
@@ -723,9 +726,10 @@ void bluetooth::shim::legacy::Acl::OnLeLinkDisconnected(HciHandle handle,
   LOG_DEBUG("Disconnected le link remote:%s handle:%hu reason:%s",
             PRIVATE_ADDRESS(remote_address_with_type), handle,
             ErrorCodeText(reason).c_str());
-  btm_cb.history_->Push("%-32s: %s le reason:%s", "Disconnected",
-                        PRIVATE_ADDRESS(remote_address_with_type),
-                        ErrorCodeText(reason).c_str());
+  BTM_LogHistory(
+      kBtmLogTag, ToLegacyAddressWithType(remote_address_with_type),
+      "Disconnected",
+      base::StringPrintf("le reason:%s", ErrorCodeText(reason).c_str()));
 }
 
 void bluetooth::shim::legacy::Acl::OnConnectSuccess(
@@ -752,10 +756,9 @@ void bluetooth::shim::legacy::Acl::OnConnectSuccess(
   LOG_DEBUG("Connection successful classic remote:%s handle:%hu initiator:%s",
             PRIVATE_ADDRESS(remote_address), handle,
             (locally_initiated) ? "local" : "remote");
-  btm_cb.history_->Push(
-      "%-32s: %s %s classic", "Connection successful",
-      PRIVATE_ADDRESS(remote_address),
-      (locally_initiated) ? "Local initiated" : "Remote initiated");
+  BTM_LogHistory(kBtmLogTag, ToRawAddress(remote_address),
+                 "Connection successful",
+                 (locally_initiated) ? "Local initiated" : "Remote initiated");
 }
 
 void bluetooth::shim::legacy::Acl::OnConnectFail(hci::Address address,
@@ -765,9 +768,9 @@ void bluetooth::shim::legacy::Acl::OnConnectFail(hci::Address address,
                       kInvalidHciHandle, ToLegacyHciErrorCode(reason), false);
   LOG_WARN("Connection failed classic remote:%s reason:%s",
            PRIVATE_ADDRESS(address), hci::ErrorCodeText(reason).c_str());
-  btm_cb.history_->Push("%-32s: %s classic reason:%s", "Connection failed",
-                        PRIVATE_ADDRESS(address),
-                        hci::ErrorCodeText(reason).c_str());
+  BTM_LogHistory(kBtmLogTag, ToRawAddress(address), "Connection failed",
+                 base::StringPrintf("classic reason:%s",
+                                    hci::ErrorCodeText(reason).c_str()));
 }
 
 void bluetooth::shim::legacy::Acl::OnLeConnectSuccess(
@@ -809,10 +812,8 @@ void bluetooth::shim::legacy::Acl::OnLeConnectSuccess(
   LOG_DEBUG("Connection successful le remote:%s handle:%hu initiator:%s",
             PRIVATE_ADDRESS(address_with_type), handle,
             (locally_initiated) ? "local" : "remote");
-  btm_cb.history_->Push(
-      "%-32s: %s %s le", "Connection successful",
-      PRIVATE_ADDRESS(address_with_type),
-      (locally_initiated) ? "Local Initiate" : "Remote initiate");
+  BTM_LogHistory(kBtmLogTag, ToLegacyAddressWithType(address_with_type),
+                 "Connection successful", "le");
 }
 
 void bluetooth::shim::legacy::Acl::OnLeConnectFail(
@@ -828,9 +829,10 @@ void bluetooth::shim::legacy::Acl::OnLeConnectFail(
                       legacy_address_with_type, handle, enhanced, status);
   LOG_WARN("Connection failed le remote:%s",
            PRIVATE_ADDRESS(address_with_type));
-  btm_cb.history_->Push("%-32s: %s le reason:%s", "Connection failed",
-                        PRIVATE_ADDRESS(address_with_type),
-                        hci::ErrorCodeText(reason).c_str());
+  BTM_LogHistory(
+      kBtmLogTag, ToLegacyAddressWithType(address_with_type),
+      "Connection failed",
+      base::StringPrintf("le reason:%s", hci::ErrorCodeText(reason).c_str()));
 }
 
 void bluetooth::shim::legacy::Acl::ConfigureLePrivacy(
@@ -867,8 +869,8 @@ void bluetooth::shim::legacy::Acl::DisconnectClassic(uint16_t handle,
         ToDisconnectReasonFromLegacy(reason));
     LOG_DEBUG("Disconnection initiated classic remote:%s handle:%hu",
               PRIVATE_ADDRESS(remote_address), handle);
-    btm_cb.history_->Push("%-32s: %s classic", "Disconnection initiated",
-                          PRIVATE_ADDRESS(remote_address));
+    BTM_LogHistory(kBtmLogTag, ToRawAddress(remote_address),
+                   "Disconnection initiated", "classic");
   } else {
     LOG_WARN("Unable to disconnect unknown classic connection handle:0x%04x",
              handle);
@@ -885,8 +887,9 @@ void bluetooth::shim::legacy::Acl::DisconnectLe(uint16_t handle,
         ToDisconnectReasonFromLegacy(reason));
     LOG_DEBUG("Disconnection initiated le remote:%s handle:%hu",
               PRIVATE_ADDRESS(remote_address_with_type), handle);
-    btm_cb.history_->Push("%-32s: %s le", "Disconnection initiated",
-                          PRIVATE_ADDRESS(remote_address_with_type));
+    BTM_LogHistory(kBtmLogTag,
+                   ToLegacyAddressWithType(remote_address_with_type),
+                   "Disconnection initiated", "le");
   } else {
     LOG_WARN("Unable to disconnect unknown le connection handle:0x%04x",
              handle);

diff --git a/stack/acl/btm_pm.cc b/stack/acl/btm_pm.cc
index fa4d52d..6da7ee1 100644 (file)
--- a/stack/acl/btm_pm.cc
+++ b/stack/acl/btm_pm.cc
@@ -30,6 +30,7 @@
 
 #define LOG_TAG "bt_btm_pm"
 
+#include <base/strings/stringprintf.h>
 #include <cstdint>
 
 #include "bt_target.h"
@@ -41,6 +42,7 @@
 #include "osi/include/log.h"
 #include "stack/btm/btm_int_types.h"
 #include "stack/include/acl_api.h"
+#include "stack/include/btm_api.h"
 #include "stack/include/btm_api_types.h"
 #include "stack/include/btm_status.h"
 #include "stack/include/l2cap_hci_link_interface.h"
@@ -60,6 +62,8 @@ struct StackAclBtmPm {
 
 namespace {
 StackAclBtmPm internal_;
+
+constexpr char kBtmLogTag[] = "ACL";
 }
 
 /*****************************************************************************/
@@ -87,11 +91,11 @@ const uint8_t
 static void send_sniff_subrating(const tACL_CONN& p_acl, uint16_t max_lat,
                                  uint16_t min_rmt_to, uint16_t min_loc_to) {
   btsnd_hcic_sniff_sub_rate(p_acl.hci_handle, max_lat, min_rmt_to, min_loc_to);
-  btm_cb.history_->Push(
-      "%-32s: %s max_latency:%.2f peer_timeout:%.2f local_timeout:%.2f",
-      "Sniff subrating (seconds)", PRIVATE_ADDRESS(p_acl.remote_addr),
-      ticks_to_seconds(max_lat), ticks_to_seconds(min_rmt_to),
-      ticks_to_seconds(min_loc_to));
+  BTM_LogHistory(kBtmLogTag, p_acl.remote_addr, "Sniff subrating",
+                 base::StringPrintf(
+                     "max_latency:%.2f peer_timeout:%.2f local_timeout:%.2f",
+                     ticks_to_seconds(max_lat), ticks_to_seconds(min_rmt_to),
+                     ticks_to_seconds(min_loc_to)));
 }
 
 /*****************************************************************************/
@@ -579,14 +583,16 @@ tBTM_STATUS StackAclBtmPm::btm_pm_snd_md_req(tACL_CONN& p_acl, uint8_t pm_id,
   /* send the appropriate HCI command */
   btm_cb.acl_cb_.pm_pend_id = pm_id;
 
-  LOG_INFO("switching from %s(0x%x) to %s(0x%x), link_ind: %d",
+  LOG_INFO("Switching from %s[0x%02x] to %s[0x%02x]",
            power_mode_state_text(p_cb->State()).c_str(), p_cb->State(),
-           power_mode_state_text(md_res.mode).c_str(), md_res.mode, link_ind);
-  btm_cb.history_->Push(
-      "%-32s: %s  %s(0x%02x) ==> %s(0x%02x)", "Power mode change",
-      PRIVATE_ADDRESS(btm_cb.acl_cb_.acl_db[link_ind].remote_addr),
-      power_mode_state_text(p_cb->State()).c_str(), p_cb->State(),
-      power_mode_state_text(md_res.mode).c_str(), md_res.mode);
+           power_mode_state_text(md_res.mode).c_str(), md_res.mode);
+  BTM_LogHistory(
+      kBtmLogTag, btm_cb.acl_cb_.acl_db[link_ind].remote_addr,
+      "Power mode change",
+      base::StringPrintf(
+          "%s[0x%02x] ==> %s[0x%02x]",
+          power_mode_state_text(p_cb->State()).c_str(), p_cb->State(),
+          power_mode_state_text(md_res.mode).c_str(), md_res.mode));
 
   switch (md_res.mode) {
     case BTM_PM_MD_ACTIVE:

diff --git a/stack/btm/btm_main.cc b/stack/btm/btm_main.cc
index e997925..531fe43 100644 (file)
--- a/stack/btm/btm_main.cc
+++ b/stack/btm/btm_main.cc
@@ -69,7 +69,7 @@ void btm_init(void) {
 
   btm_cb.history_ = std::make_shared<TimestampedStringCircularBuffer>(40);
   CHECK(btm_cb.history_ != nullptr);
-  btm_cb.history_->Push(std::string("Initialized btm history"));
+  btm_cb.history_->Push(std::string("<--- Initialized btm history --->"));
 }
 
 /** This function is called to free dynamic memory and system resource allocated by btm_init */
@@ -85,15 +85,29 @@ void btm_free(void) {
 constexpr size_t kMaxLogHistoryTagLength = 6;
 constexpr size_t kMaxLogHistoryMsgLength = 25;
 
+static void btm_log_history(const std::string& tag, const char* addr,
+                            const std::string& msg, const std::string& extra) {
+  btm_cb.history_->Push(
+      "%-6s %-25s: %s %s", tag.substr(0, kMaxLogHistoryTagLength).c_str(),
+      msg.substr(0, kMaxLogHistoryMsgLength).c_str(), addr, extra.c_str());
+}
+
 void BTM_LogHistory(const std::string& tag, const RawAddress& bd_addr,
                     const std::string& msg, const std::string& extra) {
-  btm_cb.history_->Push("%-6s %-25s: %s %s",
-                        tag.substr(0, kMaxLogHistoryTagLength).c_str(),
-                        msg.substr(0, kMaxLogHistoryMsgLength).c_str(),
-                        PRIVATE_ADDRESS(bd_addr), extra.c_str());
+  btm_log_history(tag, PRIVATE_ADDRESS(bd_addr), msg, extra);
 }
 
 void BTM_LogHistory(const std::string& tag, const RawAddress& bd_addr,
                     const std::string& msg) {
   BTM_LogHistory(tag, bd_addr, msg, std::string());
 }
+
+void BTM_LogHistory(const std::string& tag, const tBLE_BD_ADDR& ble_bd_addr,
+                    const std::string& msg, const std::string& extra) {
+  btm_log_history(tag, PRIVATE_ADDRESS(ble_bd_addr), msg, extra);
+}
+
+void BTM_LogHistory(const std::string& tag, const tBLE_BD_ADDR& ble_bd_addr,
+                    const std::string& msg) {
+  BTM_LogHistory(tag, ble_bd_addr, msg, std::string());
+}

diff --git a/stack/include/btm_api.h b/stack/include/btm_api.h
index 3f6b59c..294e1f8 100644 (file)
--- a/stack/include/btm_api.h
+++ b/stack/include/btm_api.h
@@ -951,6 +951,10 @@ void BTM_LogHistory(const std::string& tag, const RawAddress& addr,
                     const std::string& msg);
 void BTM_LogHistory(const std::string& tag, const RawAddress& addr,
                     const std::string& msg, const std::string& extra);
+void BTM_LogHistory(const std::string& tag, const tBLE_BD_ADDR& addr,
+                    const std::string& msg);
+void BTM_LogHistory(const std::string& tag, const tBLE_BD_ADDR& addr,
+                    const std::string& msg, const std::string& extra);
 
 uint8_t btm_ble_read_sec_key_size(const RawAddress& bd_addr);