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

Commit 6836c9a9 authored by Jack He's avatar Jack He
Browse files

RFCOMM: Add more logging on failure cases

* Log every instance of RFCOMM unexpected disconnection
* Log every time when RFCOMM channel (DLCI) is changed
* Refactor some RFCOMM code to be more readable and easier for logging
* Remove excessive logging in power manager
* Assign HSP default version more appropriate location
* Replace some usage of NULL with nullptr

Bug: 77224743
Test: make, no functional changes
Change-Id: I5e62dd6d338f7e92a8b8d39c1fe155b71396034c
(cherry picked from commit 0f5a1da4)
parent c7ab80f8
Loading
Loading
Loading
Loading
+3 −2
Original line number Diff line number Diff line
@@ -310,6 +310,7 @@ static tBTA_AG_SCB* bta_ag_scb_alloc(void) {
      p_scb->peer_codecs = BTA_AG_CODEC_CVSD;
      p_scb->sco_codec = BTA_AG_CODEC_CVSD;
      p_scb->peer_version = HFP_HSP_VERSION_UNKNOWN;
      p_scb->hsp_version = HSP_VERSION_1_2;
      /* set up timers */
      p_scb->ring_timer = alarm_new("bta_ag.scb_ring_timer");
      p_scb->collision_timer = alarm_new("bta_ag.scb_collision_timer");
@@ -377,12 +378,12 @@ void bta_ag_scb_dealloc(tBTA_AG_SCB* p_scb) {
 * Description      Given a pointer to an scb, return its index.
 *
 *
 * Returns          Index of scb.
 * Returns          Index of scb starting from 1
 *
 ******************************************************************************/
uint16_t bta_ag_scb_to_idx(tBTA_AG_SCB* p_scb) {
  /* use array arithmetic to determine index */
  return ((uint16_t)(p_scb - bta_ag_cb.scb)) + 1;
  return static_cast<uint16_t>(p_scb - bta_ag_cb.scb + 1);
}

/*******************************************************************************
+83 −63
Original line number Diff line number Diff line
@@ -102,44 +102,46 @@ static void bta_ag_port_cback(UNUSED_ATTR uint32_t code, uint16_t port_handle,
 ******************************************************************************/
static void bta_ag_mgmt_cback(uint32_t code, uint16_t port_handle,
                              uint16_t handle) {
  tBTA_AG_SCB* p_scb;
  uint16_t event;
  uint8_t i;
  bool found_handle = false;

  APPL_TRACE_DEBUG("ag_mgmt_cback : code = %d, port_handle = %d, handle = %d",
                   code, port_handle, handle);

  p_scb = bta_ag_scb_by_idx(handle);
  if (p_scb != nullptr) {
  tBTA_AG_SCB* p_scb = bta_ag_scb_by_idx(handle);
  APPL_TRACE_DEBUG("%s: code=%d, port_handle=%d, scb_handle=%d, p_scb=0x%08x",
                   __func__, code, port_handle, handle, p_scb);
  if (p_scb == nullptr) {
    LOG(WARNING) << __func__ << ": cannot find scb, code=" << code
                 << ", port_handle=" << port_handle << ", handle=" << handle;
    return;
  }
  /* ignore close event for port handles other than connected handle */
  if ((code != PORT_SUCCESS) && (port_handle != p_scb->conn_handle)) {
      APPL_TRACE_DEBUG("ag_mgmt_cback ignoring handle:%d", port_handle);
    LOG(WARNING) << __func__ << ": ignore open failure for unmatched "
                 << "port_handle " << port_handle << ", scb_handle=" << handle;
    return;
  }

  uint16_t event;
  if (code == PORT_SUCCESS) {
      if (p_scb->conn_handle) /* Outgoing connection */
      {
        if (port_handle == p_scb->conn_handle) found_handle = true;
      } else /* Incoming connection */
      {
        for (i = 0; i < BTA_AG_NUM_IDX; i++) {
          if (port_handle == p_scb->serv_handle[i]) found_handle = true;
    bool found_handle = false;
    if (p_scb->conn_handle) {
      /* Outgoing connection */
      if (port_handle == p_scb->conn_handle) {
        found_handle = true;
      }
    } else {
      /* Incoming connection */
      for (uint16_t service_port_handle : p_scb->serv_handle) {
        if (port_handle == service_port_handle) {
          found_handle = true;
          break;
        }
      }
    }

    if (!found_handle) {
        APPL_TRACE_ERROR(
            "bta_ag_mgmt_cback: PORT_SUCCESS, ignoring handle = %d",
            port_handle);
      LOG(ERROR) << __func__ << ": port opened successfully, but port_handle "
                 << port_handle << " is unknown"
                 << ", scb_handle=" << handle;
      return;
    }

    event = BTA_AG_RFC_OPEN_EVT;
    }
  } else if (port_handle == p_scb->conn_handle) {
    /* distinguish server close events */
    else if (port_handle == p_scb->conn_handle) {
    event = BTA_AG_RFC_CLOSE_EVT;
  } else {
    event = BTA_AG_RFC_SRV_CLOSE_EVT;
@@ -147,9 +149,8 @@ static void bta_ag_mgmt_cback(uint32_t code, uint16_t port_handle,

  tBTA_AG_DATA data = {};
  data.rfc.port_handle = port_handle;
    do_in_bta_thread(FROM_HERE, base::Bind(&bta_ag_sm_execute_by_handle, handle,
                                           event, data));
  }
  do_in_bta_thread(
      FROM_HERE, base::Bind(&bta_ag_sm_execute_by_handle, handle, event, data));
}

/*******************************************************************************
@@ -212,9 +213,17 @@ void bta_ag_port_cback_6(uint32_t code, uint16_t port_handle) {
 *
 ******************************************************************************/
void bta_ag_setup_port(tBTA_AG_SCB* p_scb, uint16_t handle) {
  uint16_t i = bta_ag_scb_to_idx(p_scb) - 1;
  int port_callback_index = bta_ag_scb_to_idx(p_scb) - 1;
  CHECK_GE(port_callback_index, 0)
      << "invalid callback index, handle=" << handle << ", bd_addr"
      << p_scb->peer_addr;
  CHECK_LT(port_callback_index,
           static_cast<int>(sizeof(bta_ag_port_cback_tbl) /
                            sizeof(bta_ag_port_cback_tbl[0])))
      << "callback index out of bound, handle=" << handle << ", bd_addr"
      << p_scb->peer_addr;
  PORT_SetEventMask(handle, BTA_AG_PORT_EV_MASK);
  PORT_SetEventCallback(handle, bta_ag_port_cback_tbl[i]);
  PORT_SetEventCallback(handle, bta_ag_port_cback_tbl[port_callback_index]);
}

/*******************************************************************************
@@ -228,30 +237,36 @@ void bta_ag_setup_port(tBTA_AG_SCB* p_scb, uint16_t handle) {
 *
 ******************************************************************************/
void bta_ag_start_servers(tBTA_AG_SCB* p_scb, tBTA_SERVICE_MASK services) {
  int i;
  int bta_ag_port_status;

  services >>= BTA_HSP_SERVICE_ID;
  for (i = 0; i < BTA_AG_NUM_IDX && services != 0; i++, services >>= 1) {
  for (int i = 0; i < BTA_AG_NUM_IDX && services != 0; i++, services >>= 1) {
    /* if service is set in mask */
    if (services & 1) {
      BTM_SetSecurityLevel(false, "", bta_ag_sec_id[i], p_scb->serv_sec_mask,
                           BT_PSM_RFCOMM, BTM_SEC_PROTO_RFCOMM,
                           bta_ag_cb.profile[i].scn);

      bta_ag_port_status = RFCOMM_CreateConnection(
      int management_callback_index = bta_ag_scb_to_idx(p_scb) - 1;
      CHECK_GE(management_callback_index, 0)
          << "invalid callback index, services=" << loghex(services)
          << ", bd_addr=" << p_scb->peer_addr;
      CHECK_LT(management_callback_index,
               static_cast<int>(sizeof(bta_ag_mgmt_cback_tbl) /
                                sizeof(bta_ag_mgmt_cback_tbl[0])))
          << "callback index out of bound, services=" << loghex(services)
          << ", bd_addr" << p_scb->peer_addr;
      int status = RFCOMM_CreateConnection(
          bta_ag_uuid[i], bta_ag_cb.profile[i].scn, true, BTA_AG_MTU,
          RawAddress::kAny, &(p_scb->serv_handle[i]),
          bta_ag_mgmt_cback_tbl[bta_ag_scb_to_idx(p_scb) - 1]);

      if (bta_ag_port_status == PORT_SUCCESS) {
          bta_ag_mgmt_cback_tbl[management_callback_index]);
      if (status == PORT_SUCCESS) {
        bta_ag_setup_port(p_scb, p_scb->serv_handle[i]);
      } else {
        /* TODO: CR#137125 to handle to error properly */
        APPL_TRACE_DEBUG(
            "bta_ag_start_servers: RFCOMM_CreateConnection returned error:%d",
            bta_ag_port_status);
        LOG(ERROR) << __func__ << ": RFCOMM_CreateConnection ERROR " << status
                   << ", p_scb=" << p_scb << ", services=" << loghex(services)
                   << ", mgmt_cback_index=" << management_callback_index;
      }
      APPL_TRACE_DEBUG("%s: p_scb=0x%08x, services=0x%04x, mgmt_cback_index=%d",
                       __func__, p_scb, services, management_callback_index);
    }
  }
}
@@ -313,16 +328,21 @@ void bta_ag_rfc_do_open(tBTA_AG_SCB* p_scb, const tBTA_AG_DATA& data) {
                       p_scb->cli_sec_mask, BT_PSM_RFCOMM, BTM_SEC_PROTO_RFCOMM,
                       p_scb->peer_scn);

  if (RFCOMM_CreateConnection(
  int management_callback_index = bta_ag_scb_to_idx(p_scb) - 1;
  int status = RFCOMM_CreateConnection(
      bta_ag_uuid[p_scb->conn_service], p_scb->peer_scn, false, BTA_AG_MTU,
      p_scb->peer_addr, &(p_scb->conn_handle),
          bta_ag_mgmt_cback_tbl[bta_ag_scb_to_idx(p_scb) - 1]) ==
      PORT_SUCCESS) {
      bta_ag_mgmt_cback_tbl[management_callback_index]);
  APPL_TRACE_DEBUG(
      "%s: p_scb=0x%08x, conn_handle=%d, mgmt_cback_index=%d,"
      " status=%d",
      __func__, p_scb, p_scb->conn_handle, management_callback_index, status);
  if (status == PORT_SUCCESS) {
    bta_ag_setup_port(p_scb, p_scb->conn_handle);
    APPL_TRACE_DEBUG("bta_ag_rfc_do_open : conn_handle = %d",
                     p_scb->conn_handle);
  } else {
    /* RFCOMM create connection failed; send ourselves RFCOMM close event */
    LOG(ERROR) << __func__ << ": RFCOMM_CreateConnection ERROR " << status
               << " for " << p_scb->peer_addr;
    bta_ag_sm_execute(p_scb, BTA_AG_RFC_CLOSE_EVT, data);
  }
}
+0 −2
Original line number Diff line number Diff line
@@ -228,8 +228,6 @@ void bta_ag_create_records(tBTA_AG_SCB* p_scb, const tBTA_AG_DATA& data) {
      }
    }
  }

  p_scb->hsp_version = HSP_VERSION_1_2;
}

/*******************************************************************************
+0 −1
Original line number Diff line number Diff line
@@ -34,7 +34,6 @@
#define BT_STACK_MODULE_ID "bluetooth"

/** Bluetooth profile interface IDs */

#define BT_PROFILE_HANDSFREE_ID "handsfree"
#define BT_PROFILE_HANDSFREE_CLIENT_ID "handsfree_client"
#define BT_PROFILE_ADVANCED_AUDIO_ID "a2dp"
+4 −5
Original line number Diff line number Diff line
@@ -163,7 +163,7 @@ tBTM_STATUS BTM_SetPowerMode(uint8_t pm_id, const RawAddress& remote_bda,
  }

  VLOG(2) << __func__ << " pm_id " << pm_id << " BDA: " << remote_bda
          << " mode:0x" << std::hex << p_mode->mode;
          << " mode:" << std::to_string(p_mode->mode);

  /* take out the force bit */
  mode = p_mode->mode & ~BTM_PM_MD_FORCE;
@@ -192,10 +192,9 @@ tBTM_STATUS BTM_SetPowerMode(uint8_t pm_id, const RawAddress& remote_bda,
         (p_mode->min <= p_cb->interval)) ||
        ((p_mode->mode & BTM_PM_MD_FORCE) == 0 &&
         (p_mode->max >= p_cb->interval))) {
      LOG(INFO) << __func__ << " already in requested mode "
                << unsigned(p_mode->mode) << ", interval "
                << unsigned(p_cb->interval) << " max " << unsigned(p_mode->max)
                << " min " << unsigned(p_mode->min);
      VLOG(1) << __func__ << " already in requested mode "
              << std::to_string(p_mode->mode) << ", interval " << p_cb->interval
              << " max " << p_mode->max << " min " << p_mode->min;
      return BTM_SUCCESS;
    }
  }
Loading