Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 62a595e9 authored by Łukasz Rymanowski's avatar Łukasz Rymanowski
Browse files

gatt: Extend dumpsys information 

With this patch  we are adding gatt state history along with information
on the gatt if holders.
This will help to debug which applications are keeping ACL connects.

e.g. logs:

stack::gatt    last 78 tcb state transitions:
stack::gatt    2024-08-09 14:51:21.415 xx:xx:xx:xx:9d:0b, BT_TRANSPORT_LE, state: GATT_CH_OPEN, No ACL holders
stack::gatt    2024-08-09 14:51:21.419 xx:xx:xx:xx:9d:0b, BT_TRANSPORT_LE, state: GATT_CH_OPEN, ACL holders gatt_if:13,
stack::gatt    2024-08-09 15:00:45.024 xx:xx:xx:xx:9d:0b, BT_TRANSPORT_LE, state: GATT_CH_CLOSE, ACL holders gatt_if:13,
stack::gatt    2024-08-09 15:00:53.335 xx:xx:xx:xx:13:0d, BT_TRANSPORT_LE, state: GATT_CH_OPEN, No ACL holders
stack::gatt    2024-08-09 15:00:53.341 xx:xx:xx:xx:13:0d, BT_TRANSPORT_LE, state: GATT_CH_OPEN, ACL holders gatt_if:12,
stack::gatt    2024-08-09 15:00:54.314 xx:xx:xx:xx:13:0d, BT_TRANSPORT_LE, state: GATT_CH_CLOSE, ACL holders gatt_if:12,

Also some additional logs are added to logcat on the same matter

Bug: 331775328
Test: mmm packages/modules/Bluetooth
Flag: EXEMPT, logging only code
Change-Id: I13aaa33a56a3a54c095ff292fa671740372251d1
parent be578012

system/stack/gatt/gatt_int.h

+32 −0
Original line number Diff line number Diff line
@@ -28,10 +28,13 @@ 
#include <unordered_set>

#include <vector>



#include "common/circular_buffer.h"

#include "common/init_flags.h"

#include "common/strings.h"

#include "gatt_api.h"

#include "internal_include/bt_target.h"

#include "macros.h"

#include "main/shim/dumpsys.h"

#include "osi/include/fixed_queue.h"

#include "stack/include/bt_hdr.h"

#include "types/bluetooth/uuid.h"
@@ -465,6 +468,34 @@ extern tGATT_CB gatt_cb; 
void gatt_set_err_rsp(bool enable, uint8_t req_op_code, uint8_t err_status);

#endif



namespace {

constexpr char kTimeFormatString[] = "%Y-%m-%d %H:%M:%S";



constexpr unsigned MillisPerSecond = 1000;

inline std::string EpochMillisToString(long long time_ms) {

  time_t time_sec = time_ms / MillisPerSecond;

  struct tm tm;

  localtime_r(&time_sec, &tm);

  std::string s = bluetooth::common::StringFormatTime(kTimeFormatString, tm);

  return base::StringPrintf("%s.%03u", s.c_str(),

                            static_cast<unsigned int>(time_ms % MillisPerSecond));

}

}  // namespace



struct tTCB_STATE_HISTORY {

  RawAddress address;

  tBT_TRANSPORT transport;

  tGATT_CH_STATE state;

  std::string holders_info;

  std::string ToString() const {

    return base::StringPrintf("%s, %s, state: %s, %s", ADDRESS_TO_LOGGABLE_CSTR(address),

                              bt_transport_text(transport).c_str(),

                              gatt_channel_state_text(state).c_str(), holders_info.c_str());

  }

};



extern bluetooth::common::TimestampedCircularBuffer<tTCB_STATE_HISTORY> tcb_state_history_;



/* from gatt_main.cc */

bool gatt_disconnect(tGATT_TCB* p_tcb);

void gatt_cancel_connect(const RawAddress& bd_addr, tBT_TRANSPORT transport);
@@ -584,6 +615,7 @@ bool gatt_tcb_get_cid_available_for_indication(tGATT_TCB* p_tcb, bool eatt_suppo 
bool gatt_tcb_find_indicate_handle(tGATT_TCB& tcb, uint16_t cid, uint16_t* indicated_handle_p);

uint16_t gatt_tcb_get_att_cid(tGATT_TCB& tcb, bool eatt_support);

uint16_t gatt_tcb_get_payload_size(tGATT_TCB& tcb, uint16_t cid);

std::string gatt_tcb_get_holders_info_string(const tGATT_TCB* p_tcb);

void gatt_clcb_invalidate(tGATT_TCB* p_tcb, const tGATT_CLCB* p_clcb);

uint16_t gatt_get_mtu(const RawAddress& bda, tBT_TRANSPORT transport);

bool gatt_is_pending_mtu_exchange(tGATT_TCB* p_tcb);

system/stack/gatt/gatt_main.cc

+34 −3
Original line number Diff line number Diff line
@@ -55,6 +55,9 @@ 
using bluetooth::eatt::EattExtension;

using namespace bluetooth;



bluetooth::common::TimestampedCircularBuffer<tTCB_STATE_HISTORY> tcb_state_history_(

        100 /*history size*/);



/******************************************************************************/

/*            L O C A L    F U N C T I O N     P R O T O T Y P E S            */

/******************************************************************************/
@@ -338,6 +341,12 @@ static bool gatt_update_app_hold_link_status(tGATT_IF gatt_if, tGATT_TCB* p_tcb, 
    } else {

      log::warn("attempt to add already existing gatt_if={}", gatt_if);

    }



    auto holders_string = gatt_tcb_get_holders_info_string(p_tcb);

    tcb_state_history_.Push({.address = p_tcb->peer_bda,

                             .transport = p_tcb->transport,

                             .state = p_tcb->ch_state,

                             .holders_info = holders_string});

    return true;

  }
@@ -348,6 +357,12 @@ static bool gatt_update_app_hold_link_status(tGATT_IF gatt_if, tGATT_TCB* p_tcb, 
  }



  log::info("removed gatt_if={}", gatt_if);



  auto holders_string = gatt_tcb_get_holders_info_string(p_tcb);

  tcb_state_history_.Push({.address = p_tcb->peer_bda,

                           .transport = p_tcb->transport,

                           .state = p_tcb->ch_state,

                           .holders_info = holders_string});

  return true;

}
@@ -416,7 +431,13 @@ void gatt_update_app_use_link_flag(tGATT_IF gatt_if, tGATT_TCB* p_tcb, bool is_a 
        gatt_disconnect(p_tcb);

      }

    } else {

      log::info("is_add=false, but some app is still using the ACL link");

      auto holders = gatt_tcb_get_holders_info_string(p_tcb);

      log::info("is_add=false, but some app is still using the ACL link. {}", holders);



      tcb_state_history_.Push({.address = p_tcb->peer_bda,

                               .transport = p_tcb->transport,

                               .state = p_tcb->ch_state,

                               .holders_info = holders});

    }

  }

}
@@ -1261,7 +1282,16 @@ void gatt_set_ch_state(tGATT_TCB* p_tcb, tGATT_CH_STATE ch_state) { 
    return;

  }



  log::verbose("old={} new=0x{:x}", p_tcb->ch_state, static_cast<uint8_t>(ch_state));

  std::string holders_string = gatt_tcb_get_holders_info_string(p_tcb);

  log::verbose("{}, transport: {}, state: {} -> {}, {}", p_tcb->peer_bda,

               bt_transport_text(p_tcb->transport), gatt_channel_state_text(p_tcb->ch_state),

               gatt_channel_state_text(ch_state), holders_string);



  tcb_state_history_.Push({.address = p_tcb->peer_bda,

                           .transport = p_tcb->transport,

                           .state = ch_state,

                           .holders_info = holders_string});



  p_tcb->ch_state = ch_state;

}
@@ -1271,6 +1301,7 @@ tGATT_CH_STATE gatt_get_ch_state(tGATT_TCB* p_tcb) { 
    return GATT_CH_CLOSE;

  }



  log::verbose("gatt_get_ch_state: ch_state={}", p_tcb->ch_state);

  log::verbose("{}, transport {},  ch_state={}", p_tcb->peer_bda,

               bt_transport_text(p_tcb->transport), gatt_channel_state_text(p_tcb->ch_state));

  return p_tcb->ch_state;

}

system/stack/gatt/gatt_utils.cc

+26 −2
Original line number Diff line number Diff line
@@ -453,6 +453,21 @@ tGATT_TCB* gatt_find_tcb_by_addr(const RawAddress& bda, tBT_TRANSPORT transport) 
  return p_tcb;

}



std::string gatt_tcb_get_holders_info_string(const tGATT_TCB* p_tcb) {

  std::stringstream stream;



  if (p_tcb->app_hold_link.size() == 0) {

    stream << "No ACL holders";

  } else {

    stream << "ACL holders gatt_if:";



    for (auto gatt_if : p_tcb->app_hold_link) {

      stream << static_cast<int>(gatt_if) << ",";

    }

  }

  return stream.str();

}



/*******************************************************************************

 *

 * Function     gatt_tcb_dump
@@ -462,10 +477,18 @@ tGATT_TCB* gatt_find_tcb_by_addr(const RawAddress& bda, tBT_TRANSPORT transport) 
 * Returns      void

 *

 ******************************************************************************/

#define DUMPSYS_TAG "stack::gatt"

void gatt_tcb_dump(int fd) {

  std::stringstream stream;

  int in_use_cnt = 0;



  auto copy = tcb_state_history_.Pull();

  LOG_DUMPSYS(fd, "   last %zu tcb state transitions:", copy.size());

  for (const auto& it : copy) {

    LOG_DUMPSYS(fd, "   %s %s", EpochMillisToString(it.timestamp).c_str(),

                it.entry.ToString().c_str());

  }



  for (int i = 0; i < gatt_get_max_phy_channel(); i++) {

    tGATT_TCB* p_tcb = &gatt_cb.tcb[i];
@@ -474,14 +497,15 @@ void gatt_tcb_dump(int fd) { 
      stream << "  id: " << +p_tcb->tcb_idx

             << "  address: " << ADDRESS_TO_LOGGABLE_STR(p_tcb->peer_bda)

             << "  transport: " << bt_transport_text(p_tcb->transport)

             << "  ch_state: " << gatt_channel_state_text(p_tcb->ch_state);

      stream << "\n";

             << "  ch_state: " << gatt_channel_state_text(p_tcb->ch_state) << ", "

             << gatt_tcb_get_holders_info_string(p_tcb) << "\n";

    }

  }



  dprintf(fd, "TCB (GATT_MAX_PHY_CHANNEL: %d) in_use: %d\n%s\n", gatt_get_max_phy_channel(),

          in_use_cnt, stream.str().c_str());

}

#undef DUMPSYS_TAG



/*******************************************************************************

 *

system/stack/test/common/mock_gatt_layer.cc

+3 −0
Original line number Diff line number Diff line
@@ -21,6 +21,9 @@ 


static bluetooth::gatt::MockGattInterface* gatt_interface = nullptr;



bluetooth::common::TimestampedCircularBuffer<tTCB_STATE_HISTORY> tcb_state_history_(

        100 /*history size*/);



void bluetooth::gatt::SetMockGattInterface(MockGattInterface* mock_gatt_interface) {

  gatt_interface = mock_gatt_interface;

}