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

Commit 2c1d8847 authored by Ugo Yu's avatar Ugo Yu
Browse files

Gracefully handle startup timer expiry

* Close HCI when startup timer has expired as a signal of error to
  the Bluetooth HAL.
* Do not handle H/W error event if the stack has already received
  root inflammtion event.
* Correctly handle initializeComplete callback after receives a root
  inflammation event.

Bug: 144572644
Test: Manual
Change-Id: Ic165ff1340bcada5d71668ac76e71ef67f2643fd
parent ea4b7371
Loading
Loading
Loading
Loading
+1 −0
Original line number Diff line number Diff line
@@ -100,3 +100,4 @@ const hci_t* hci_layer_get_test_interface(
void post_to_main_message_loop(const base::Location& from_here, BT_HDR* p_msg);

void hci_layer_cleanup_interface();
bool hci_is_root_inflammation_event_received();
+46 −30
Original line number Diff line number Diff line
@@ -88,6 +88,7 @@ typedef struct {
static const uint32_t COMMAND_PENDING_TIMEOUT_MS = 2000;
static const uint32_t COMMAND_PENDING_MUTEX_ACQUIRE_TIMEOUT_MS = 500;
static const uint32_t COMMAND_TIMEOUT_RESTART_MS = 5000;
static const uint32_t ROOT_INFLAMMED_RESTART_MS = 5000;
static const int HCI_UNKNOWN_COMMAND_TIMED_OUT = 0x00ffffff;
static const int HCI_STARTUP_TIMED_OUT = 0x00eeeeee;

@@ -366,6 +367,13 @@ static void startup_timer_expired(UNUSED_ATTR void* context) {
  LOG_ERROR(LOG_TAG, "%s", __func__);

  LOG_EVENT_INT(BT_HCI_TIMEOUT_TAG_NUM, HCI_STARTUP_TIMED_OUT);

  hci_close();
  if (abort_timer.IsScheduled()) {
    LOG_ERROR(LOG_TAG, "%s: waiting for abort_timer", __func__);
    return;
  }

  abort();
}

@@ -567,6 +575,43 @@ void process_command_credits(int credits) {
  }
}

bool hci_is_root_inflammation_event_received() {
  return abort_timer.IsScheduled();
}

void handle_root_inflammation_event(uint8_t error_code,
                                    uint8_t vendor_error_code) {
  LOG(ERROR) << __func__
             << ": Root inflammation event! setting timer to restart.";
  // TODO(ugoyu) Report to bluetooth metrics here
  {
    // Try to stop hci command and startup timers
    std::unique_lock<std::recursive_timed_mutex> lock(
        commands_pending_response_mutex, std::defer_lock);
    if (lock.try_lock_for(std::chrono::milliseconds(
            COMMAND_PENDING_MUTEX_ACQUIRE_TIMEOUT_MS))) {
      if (alarm_is_scheduled(startup_timer)) {
        alarm_cancel(startup_timer);
      }
      if (alarm_is_scheduled(command_response_timer)) {
        alarm_cancel(command_response_timer);
      }
    } else {
      LOG(ERROR) << __func__ << ": Failed to obtain mutex";
    }
  }

  // HwBinder thread post to hci_thread
  if (!hci_thread.IsRunning() ||
      !abort_timer.Schedule(
          hci_thread.GetWeakPtr(), FROM_HERE,
          base::Bind(hci_root_inflamed_abort, error_code, vendor_error_code),
          base::TimeDelta::FromMilliseconds(ROOT_INFLAMMED_RESTART_MS))) {
    LOG(ERROR) << "Failed to schedule abort_timer or hci has already closed!";
    hci_root_inflamed_abort(error_code, vendor_error_code);
  }
}

// Returns true if the event was intercepted and should not proceed to
// higher layers. Also inspects an incoming event for interesting
// information, like how many commands are now able to be sent.
@@ -654,36 +699,7 @@ static bool filter_incoming_event(BT_HDR* packet) {
        uint8_t vendor_error_code;
        STREAM_TO_UINT8(error_code, stream);
        STREAM_TO_UINT8(vendor_error_code, stream);
        // TODO(ugoyu) Report to bluetooth metrics here

        LOG(ERROR) << __func__
                   << ": Root inflammation event! setting timer to restart.";
        {
          // Try to stop hci command and startup timers
          std::unique_lock<std::recursive_timed_mutex> lock(
              commands_pending_response_mutex, std::defer_lock);
          if (lock.try_lock_for(std::chrono::milliseconds(
                  COMMAND_PENDING_MUTEX_ACQUIRE_TIMEOUT_MS))) {
            if (alarm_is_scheduled(startup_timer)) {
              alarm_cancel(startup_timer);
            }
            if (alarm_is_scheduled(command_response_timer)) {
              alarm_cancel(command_response_timer);
            }
          } else {
            LOG(ERROR) << __func__ << ": Failed to obtain mutex";
          }
        }

        // HwBinder thread post to hci_thread
        if (!abort_timer.Schedule(hci_thread.GetWeakPtr(), FROM_HERE,
                                  base::Bind(hci_root_inflamed_abort,
                                             error_code, vendor_error_code),
                                  base::TimeDelta::FromMilliseconds(
                                      COMMAND_TIMEOUT_RESTART_MS))) {
          LOG(ERROR) << "Failed to schedule abort_timer!";
          hci_root_inflamed_abort(error_code, vendor_error_code);
        }
        handle_root_inflammation_event(error_code, vendor_error_code);
      }
    }
  }
+15 −2
Original line number Diff line number Diff line
@@ -55,6 +55,7 @@ extern void acl_event_received(BT_HDR* packet);
extern void sco_data_received(BT_HDR* packet);
extern void iso_data_received(BT_HDR* packet);
extern void hal_service_died();
extern bool hci_is_root_inflammation_event_received();

android::sp<V1_0::IBluetoothHci> btHci;
android::sp<V1_1::IBluetoothHci> btHci_1_1;
@@ -89,6 +90,15 @@ class BluetoothHciCallbacks : public V1_1::IBluetoothHciCallbacks {
  }

  Return<void> initializationComplete(Status status) override {
    if (hci_is_root_inflammation_event_received()) {
      // Ignore the initializationComplete here as we have already received
      // root inflammation event earlier.
      LOG_ERROR(
          LOG_TAG,
          "initializationComplete after root inflammation event! status=%d",
          status);
      return Void();
    }
    CHECK(status == Status::SUCCESS);
    initialization_complete();
    return Void();
@@ -160,10 +170,13 @@ void hci_close() {
    if (!death_unlink.isOk()) {
      LOG_ERROR(LOG_TAG, "%s: Error unlinking death recipient from the Bluetooth HAL", __func__);
    }
    auto close_status = btHci->close();
    if (!close_status.isOk()) {
      LOG_ERROR(LOG_TAG, "%s: Error closing the Bluetooth HAL", __func__);
    }
  btHci->close();
    btHci = nullptr;
  }
}

void hci_transmit(BT_HDR* packet) {
  HciPacket data;
+6 −0
Original line number Diff line number Diff line
@@ -1647,6 +1647,12 @@ static void btu_hcif_command_status_evt(uint8_t status, BT_HDR* command,
 ******************************************************************************/
static void btu_hcif_hardware_error_evt(uint8_t* p) {
  HCI_TRACE_ERROR("Ctlr H/w error event - code:0x%x", *p);
  if (hci_is_root_inflammation_event_received()) {
    // Ignore the hardware error event here as we have already received
    // root inflammation event earlier.
    HCI_TRACE_ERROR(LOG_TAG, "H/w error event after root inflammation event!");
    return;
  }

  /* If anyone wants device status notifications, give him one. */
  btm_report_device_status(BTM_DEV_STATUS_DOWN);