bluetooth: Add initialization completed callback

Test: bluetooth_hidl_hal_test
Bug: 31972505
Change-Id: I64c19a7fe7299079c5daf74e7b238b0d71d65db2
diff --git a/bluetooth/1.0/IBluetoothHci.hal b/bluetooth/1.0/IBluetoothHci.hal
index 10cf914..8722616 100644
--- a/bluetooth/1.0/IBluetoothHci.hal
+++ b/bluetooth/1.0/IBluetoothHci.hal
@@ -35,12 +35,18 @@
      * required to communicate with the Bluetooth hardware in the
      * device.
      *
+     * The |oninitializationComplete| callback must be invoked in response
+     * to this function to indicate success before any other function
+     * (sendHciCommand, sendAclData, * sendScoData) is invoked on this
+     * interface.
+     *
      * @param callback implements IBluetoothHciCallbacks which will
      *    receive callbacks when incoming HCI packets are received
      *    from the controller to be sent to the host.
-     * @return status result of the initialization
      */
-    initialize(IBluetoothHciCallbacks callback) generates (Status status);
+    @entry
+    @callflow(next={"sendHciCommand", "sendAclData", "sendScoData", "close"})
+    initialize(IBluetoothHciCallbacks callback);
 
     /**
      * Send an HCI command (as specified in the Bluetooth Specification
@@ -49,6 +55,7 @@
      *
      * @param command is the HCI command to be sent
      */
+    @callflow(next={"sendHciCommand", "sendAclData", "sendScoData", "close"})
     sendHciCommand(HciPacket command);
 
     /**
@@ -57,6 +64,7 @@
      * Packets must be processed in order.
      * @param data HCI data packet to be sent
      */
+    @callflow(next={"sendHciCommand", "sendAclData", "sendScoData", "close"})
     sendAclData(HciPacket data);
 
     /**
@@ -65,10 +73,12 @@
      * Packets must be processed in order.
      * @param data HCI data packet to be sent
      */
+    @callflow(next={"sendHciCommand", "sendAclData", "sendScoData", "close"})
     sendScoData(HciPacket data);
 
     /**
      * Close the HCI interface
      */
+    @exit
     close();
 };
diff --git a/bluetooth/1.0/IBluetoothHciCallbacks.hal b/bluetooth/1.0/IBluetoothHciCallbacks.hal
index afaab6c..15db1ce 100644
--- a/bluetooth/1.0/IBluetoothHciCallbacks.hal
+++ b/bluetooth/1.0/IBluetoothHciCallbacks.hal
@@ -19,21 +19,27 @@
 /* The interface from the Bluetooth Controller to the stack. */
 interface IBluetoothHciCallbacks {
     /**
+     * Invoked when the Bluetooth controller initialization has been
+     * completed.
+     */
+    initializationComplete(Status status);
+
+    /**
      * This function is invoked when an HCI event is received from the
      * Bluetooth controller to be forwarded to the Bluetooth stack.
      * @param event is the HCI event to be sent to the Bluetooth stack.
      */
-    oneway hciEventReceived(HciPacket event);
+    hciEventReceived(HciPacket event);
 
     /**
      * Send an ACL data packet form the controller to the host.
      * @param data the ACL HCI packet to be passed to the host stack
      */
-    oneway aclDataReceived(HciPacket data);
+    aclDataReceived(HciPacket data);
 
     /**
      * Send a SCO data packet form the controller to the host.
      * @param data the SCO HCI packet to be passed to the host stack
      */
-    oneway scoDataReceived(HciPacket data);
+    scoDataReceived(HciPacket data);
 };
diff --git a/bluetooth/1.0/default/bluetooth_hci.cc b/bluetooth/1.0/default/bluetooth_hci.cc
index d12bfb9..1559119 100644
--- a/bluetooth/1.0/default/bluetooth_hci.cc
+++ b/bluetooth/1.0/default/bluetooth_hci.cc
@@ -30,12 +30,16 @@
 static const uint8_t HCI_DATA_TYPE_ACL = 2;
 static const uint8_t HCI_DATA_TYPE_SCO = 3;
 
-Return<Status> BluetoothHci::initialize(
+Return<void> BluetoothHci::initialize(
     const ::android::sp<IBluetoothHciCallbacks>& cb) {
   ALOGW("BluetoothHci::initialize()");
   event_cb_ = cb;
 
   bool rc = VendorInterface::Initialize(
+      [this](bool status) {
+        event_cb_->initializationComplete(
+            status ? Status::SUCCESS : Status::INITIALIZATION_ERROR);
+      },
       [this](HciPacketType type, const hidl_vec<uint8_t>& packet) {
         switch (type) {
           case HCI_PACKET_TYPE_EVENT:
@@ -52,9 +56,8 @@
             break;
         }
       });
-  if (!rc) return Status::INITIALIZATION_ERROR;
-
-  return Status::SUCCESS;
+  if (!rc) event_cb_->initializationComplete(Status::INITIALIZATION_ERROR);
+  return Void();
 }
 
 Return<void> BluetoothHci::close() {
diff --git a/bluetooth/1.0/default/bluetooth_hci.h b/bluetooth/1.0/default/bluetooth_hci.h
index d297570..da1b411 100644
--- a/bluetooth/1.0/default/bluetooth_hci.h
+++ b/bluetooth/1.0/default/bluetooth_hci.h
@@ -32,7 +32,7 @@
 
 class BluetoothHci : public IBluetoothHci {
  public:
-  Return<Status> initialize(
+  Return<void> initialize(
       const ::android::sp<IBluetoothHciCallbacks>& cb) override;
   Return<void> sendHciCommand(const hidl_vec<uint8_t>& packet) override;
   Return<void> sendAclData(const hidl_vec<uint8_t>& data) override;
diff --git a/bluetooth/1.0/default/vendor_interface.cc b/bluetooth/1.0/default/vendor_interface.cc
index 905e1a6..20b30ae 100644
--- a/bluetooth/1.0/default/vendor_interface.cc
+++ b/bluetooth/1.0/default/vendor_interface.cc
@@ -35,6 +35,7 @@
 namespace {
 
 using android::hardware::bluetooth::V1_0::implementation::VendorInterface;
+using android::hardware::hidl_vec;
 
 tINT_CMD_CBACK internal_command_cb;
 VendorInterface* g_vendor_interface = nullptr;
@@ -46,17 +47,14 @@
     0, HCI_LENGTH_OFFSET_CMD, HCI_LENGTH_OFFSET_ACL, HCI_LENGTH_OFFSET_SCO,
     HCI_LENGTH_OFFSET_EVT};
 
-size_t HciGetPacketLengthForType(
-    HciPacketType type, const android::hardware::hidl_vec<uint8_t>& packet) {
+size_t HciGetPacketLengthForType(HciPacketType type,
+                                 const hidl_vec<uint8_t>& packet) {
   size_t offset = packet_length_offset_for_type[type];
-  if (type == HCI_PACKET_TYPE_ACL_DATA) {
-    return (((packet[offset + 1]) << 8) | packet[offset]);
-  }
-  return packet[offset];
+  if (type != HCI_PACKET_TYPE_ACL_DATA) return packet[offset];
+  return (((packet[offset + 1]) << 8) | packet[offset]);
 }
 
-HC_BT_HDR* WrapPacketAndCopy(uint16_t event,
-                             const android::hardware::hidl_vec<uint8_t>& data) {
+HC_BT_HDR* WrapPacketAndCopy(uint16_t event, const hidl_vec<uint8_t>& data) {
   size_t packet_size = data.size() + sizeof(HC_BT_HDR);
   HC_BT_HDR* packet = reinterpret_cast<HC_BT_HDR*>(new uint8_t[packet_size]);
   packet->offset = 0;
@@ -71,17 +69,16 @@
 
 uint8_t transmit_cb(uint16_t opcode, void* buffer, tINT_CMD_CBACK callback) {
   ALOGV("%s opcode: 0x%04x, ptr: %p", __func__, opcode, buffer);
-  HC_BT_HDR* bt_hdr = reinterpret_cast<HC_BT_HDR*>(buffer);
-
   internal_command_cb = callback;
   uint8_t type = HCI_PACKET_TYPE_COMMAND;
-  VendorInterface::get()->SendPrivate(&type, 1);
-  VendorInterface::get()->SendPrivate(bt_hdr->data, bt_hdr->len);
+  VendorInterface::get()->Send(&type, 1);
+  HC_BT_HDR* bt_hdr = reinterpret_cast<HC_BT_HDR*>(buffer);
+  VendorInterface::get()->Send(bt_hdr->data, bt_hdr->len);
   return true;
 }
 
 void firmware_config_cb(bt_vendor_op_result_t result) {
-  ALOGD("%s result: %d", __func__, result);
+  ALOGV("%s result: %d", __func__, result);
   VendorInterface::get()->OnFirmwareConfigured(result);
 }
 
@@ -131,10 +128,28 @@
 namespace V1_0 {
 namespace implementation {
 
-bool VendorInterface::Initialize(PacketReadCallback packet_read_cb) {
+class FirmwareStartupTimer {
+ public:
+  FirmwareStartupTimer() : start_time_(std::chrono::steady_clock::now()) {}
+
+  ~FirmwareStartupTimer() {
+    std::chrono::duration<double> duration =
+        std::chrono::steady_clock::now() - start_time_;
+    double s = duration.count();
+    if (s == 0) return;
+    ALOGD("Firmware configured in %.3fs", s);
+  }
+
+ private:
+  std::chrono::steady_clock::time_point start_time_;
+};
+
+bool VendorInterface::Initialize(
+    InitializeCompleteCallback initialize_complete_cb,
+    PacketReadCallback packet_read_cb) {
   assert(!g_vendor_interface);
   g_vendor_interface = new VendorInterface();
-  return g_vendor_interface->Open(packet_read_cb);
+  return g_vendor_interface->Open(initialize_complete_cb, packet_read_cb);
 }
 
 void VendorInterface::Shutdown() {
@@ -146,8 +161,9 @@
 
 VendorInterface* VendorInterface::get() { return g_vendor_interface; }
 
-bool VendorInterface::Open(PacketReadCallback packet_read_cb) {
-  firmware_configured_ = false;
+bool VendorInterface::Open(InitializeCompleteCallback initialize_complete_cb,
+                           PacketReadCallback packet_read_cb) {
+  initialize_complete_cb_ = initialize_complete_cb;
   packet_read_cb_ = packet_read_cb;
 
   // Initialize vendor interface
@@ -209,6 +225,7 @@
                                          [this](int fd) { OnDataReady(fd); });
 
   // Start configuring the firmware
+  firmware_startup_timer_ = new FirmwareStartupTimer();
   lib_interface_->op(BT_VND_OP_FW_CFG, nullptr);
 
   return true;
@@ -229,31 +246,13 @@
     lib_handle_ = nullptr;
   }
 
-  firmware_configured_ = false;
+  if (firmware_startup_timer_ != nullptr) {
+    delete firmware_startup_timer_;
+    firmware_startup_timer_ = nullptr;
+  }
 }
 
 size_t VendorInterface::Send(const uint8_t* data, size_t length) {
-  if (firmware_configured_ && queued_data_.size() == 0)
-    return SendPrivate(data, length);
-
-  if (!firmware_configured_) {
-    ALOGI("%s queueing command", __func__);
-    queued_data_.resize(queued_data_.size() + length);
-    uint8_t* append_ptr = &queued_data_[queued_data_.size() - length];
-    memcpy(append_ptr, data, length);
-    return length;
-  }
-
-  ALOGI("%s sending queued command", __func__);
-  SendPrivate(queued_data_.data(), queued_data_.size());
-  queued_data_.resize(0);
-
-  ALOGI("%s done sending queued command", __func__);
-
-  return SendPrivate(data, length);
-}
-
-size_t VendorInterface::SendPrivate(const uint8_t* data, size_t length) {
   if (uart_fd_ == INVALID_FD) return 0;
 
   size_t transmitted_length = 0;
@@ -280,9 +279,18 @@
 }
 
 void VendorInterface::OnFirmwareConfigured(uint8_t result) {
-  ALOGI("%s: result = %d", __func__, result);
-  firmware_configured_ = true;
-  VendorInterface::get()->Send(NULL, 0);
+  ALOGD("%s result: %d", __func__, result);
+  internal_command_cb = nullptr;
+
+  if (firmware_startup_timer_ != nullptr) {
+    delete firmware_startup_timer_;
+    firmware_startup_timer_ = nullptr;
+  }
+
+  if (initialize_complete_cb_ != nullptr) {
+    initialize_complete_cb_(result == 0);
+    initialize_complete_cb_ = nullptr;
+  }
 }
 
 void VendorInterface::OnDataReady(int fd) {
@@ -331,16 +339,17 @@
       hci_packet_bytes_remaining_ -= bytes_read;
       hci_packet_bytes_read_ += bytes_read;
       if (hci_packet_bytes_remaining_ == 0) {
-        if (firmware_configured_) {
-          if (packet_read_cb_ != nullptr) {
-            packet_read_cb_(hci_packet_type_, hci_packet_);
-          }
+        if (internal_command_cb != nullptr) {
+          HC_BT_HDR* bt_hdr =
+              WrapPacketAndCopy(HCI_PACKET_TYPE_EVENT, hci_packet_);
+          internal_command_cb(bt_hdr);
+        } else if (packet_read_cb_ != nullptr &&
+                   initialize_complete_cb_ == nullptr) {
+          packet_read_cb_(hci_packet_type_, hci_packet_);
         } else {
-          if (internal_command_cb != nullptr) {
-            HC_BT_HDR* bt_hdr =
-                WrapPacketAndCopy(HCI_PACKET_TYPE_EVENT, hci_packet_);
-            internal_command_cb(bt_hdr);
-          }
+          ALOGE(
+              "%s HCI_PAYLOAD received without packet_read_cb or pending init.",
+              __func__);
         }
         hci_parser_state_ = HCI_IDLE;
       }
diff --git a/bluetooth/1.0/default/vendor_interface.h b/bluetooth/1.0/default/vendor_interface.h
index 73ff2eb..450b99c 100644
--- a/bluetooth/1.0/default/vendor_interface.h
+++ b/bluetooth/1.0/default/vendor_interface.h
@@ -29,55 +29,50 @@
 namespace implementation {
 
 using ::android::hardware::hidl_vec;
+using InitializeCompleteCallback = std::function<void(bool success)>;
 using PacketReadCallback =
     std::function<void(HciPacketType, const hidl_vec<uint8_t> &)>;
 
+class FirmwareStartupTimer;
+
 class VendorInterface {
  public:
-  static bool Initialize(PacketReadCallback packet_read_cb);
+  static bool Initialize(InitializeCompleteCallback initialize_complete_cb,
+                         PacketReadCallback packet_read_cb);
   static void Shutdown();
-  static VendorInterface* get();
+  static VendorInterface *get();
 
   size_t Send(const uint8_t *data, size_t length);
 
   void OnFirmwareConfigured(uint8_t result);
 
-  // Actually send the data.
-  size_t SendPrivate(const uint8_t *data, size_t length);
-
  private:
-  VendorInterface() { queued_data_.resize(0); }
   virtual ~VendorInterface() = default;
 
-  bool Open(PacketReadCallback packet_read_cb);
+  bool Open(InitializeCompleteCallback initialize_complete_cb, PacketReadCallback packet_read_cb);
   void Close();
 
   void OnDataReady(int fd);
 
-  // Queue data from Send() until the interface is ready.
-  hidl_vec<uint8_t> queued_data_;
-
   void *lib_handle_;
   bt_vendor_interface_t *lib_interface_;
   AsyncFdWatcher fd_watcher_;
   int uart_fd_;
   PacketReadCallback packet_read_cb_;
-  bool firmware_configured_;
+  InitializeCompleteCallback initialize_complete_cb_;
 
-  enum HciParserState {
-    HCI_IDLE,
-    HCI_TYPE_READY,
-    HCI_PAYLOAD
-  };
+  enum HciParserState { HCI_IDLE, HCI_TYPE_READY, HCI_PAYLOAD };
   HciParserState hci_parser_state_{HCI_IDLE};
   HciPacketType hci_packet_type_{HCI_PACKET_TYPE_UNKNOWN};
   hidl_vec<uint8_t> hci_packet_;
   size_t hci_packet_bytes_remaining_;
   size_t hci_packet_bytes_read_;
+
+  FirmwareStartupTimer *firmware_startup_timer_;
 };
 
-} // namespace implementation
-} // namespace V1_0
-} // namespace bluetooth
-} // namespace hardware
-} // namespace android
+}  // namespace implementation
+}  // namespace V1_0
+}  // namespace bluetooth
+}  // namespace hardware
+}  // namespace android
diff --git a/bluetooth/1.0/vts/functional/bluetooth_hidl_hal_test.cpp b/bluetooth/1.0/vts/functional/bluetooth_hidl_hal_test.cpp
index 2a4bbdd..2ba5bb4 100644
--- a/bluetooth/1.0/vts/functional/bluetooth_hidl_hal_test.cpp
+++ b/bluetooth/1.0/vts/functional/bluetooth_hidl_hal_test.cpp
@@ -43,6 +43,7 @@
 #define NUM_HCI_COMMANDS_BANDWIDTH 1000
 #define NUM_SCO_PACKETS_BANDWIDTH 1000
 #define NUM_ACL_PACKETS_BANDWIDTH 1000
+#define WAIT_FOR_INIT_TIMEOUT std::chrono::milliseconds(2000)
 #define WAIT_FOR_HCI_EVENT_TIMEOUT std::chrono::milliseconds(2000)
 #define WAIT_FOR_SCO_DATA_TIMEOUT std::chrono::milliseconds(1000)
 #define WAIT_FOR_ACL_DATA_TIMEOUT std::chrono::milliseconds(1000)
@@ -135,6 +136,8 @@
     max_acl_data_packets = 0;
     max_sco_data_packets = 0;
 
+    initialized = false;
+    initialized_count = 0;
     event_count = 0;
     acl_count = 0;
     sco_count = 0;
@@ -142,9 +145,12 @@
     acl_cb_count = 0;
     sco_cb_count = 0;
 
-    // Collision with android::hardware::Status
-    EXPECT_EQ(android::hardware::bluetooth::V1_0::Status::SUCCESS,
-              bluetooth->initialize(bluetooth_cb));
+    ASSERT_EQ(initialized, false);
+    bluetooth->initialize(bluetooth_cb);
+
+    wait_for_init_callback();
+
+    ASSERT_EQ(initialized, true);
   }
 
   virtual void TearDown() override {
@@ -167,6 +173,26 @@
   void wait_for_command_complete_event(hidl_vec<uint8_t> cmd);
   int wait_for_completed_packets_event(uint16_t handle);
 
+  // Inform the test about the initialization callback
+  inline void notify_initialized() {
+    std::unique_lock<std::mutex> lock(initialized_mutex);
+    initialized_count++;
+    initialized_condition.notify_one();
+  }
+
+  // Test code calls this function to wait for the init callback
+  inline void wait_for_init_callback() {
+    std::unique_lock<std::mutex> lock(initialized_mutex);
+
+    auto start_time = std::chrono::steady_clock::now();
+    while (initialized_count == 0)
+      if (initialized_condition.wait_until(lock,
+                                     start_time + WAIT_FOR_INIT_TIMEOUT) ==
+          std::cv_status::timeout)
+        return;
+    initialized_count--;
+  }
+
   // Inform the test about an event callback
   inline void notify_event_received() {
     std::unique_lock<std::mutex> lock(event_mutex);
@@ -230,6 +256,13 @@
 
     virtual ~BluetoothHciCallbacks() = default;
 
+    Return<void> initializationComplete(Status status) override {
+      parent_.initialized = true;
+      parent_.notify_initialized();
+      ALOGV("%s (status = %d)", __func__, static_cast<int>(status));
+      return Void();
+    };
+
     Return<void> hciEventReceived(
         const ::android::hardware::hidl_vec<uint8_t>& event) override {
       parent_.event_cb_count++;
@@ -262,6 +295,8 @@
   std::queue<hidl_vec<uint8_t>> acl_queue;
   std::queue<hidl_vec<uint8_t>> sco_queue;
 
+  bool initialized;
+
   int event_cb_count;
   int sco_cb_count;
   int acl_cb_count;
@@ -272,12 +307,15 @@
   int max_sco_data_packets;
 
  private:
+  std::mutex initialized_mutex;
   std::mutex event_mutex;
   std::mutex sco_mutex;
   std::mutex acl_mutex;
+  std::condition_variable initialized_condition;
   std::condition_variable event_condition;
   std::condition_variable sco_condition;
   std::condition_variable acl_condition;
+  int initialized_count;
   int event_count;
   int sco_count;
   int acl_count;