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

Commit f20f383a authored by Hyundo Moon's avatar Hyundo Moon
Browse files

Print warn log when rotation happens outside expected time range 

Bug: 344712454
Bug: 360743527
Test: m com.android.btservices
Test: Manual, checked warn log by creating error in rotation time
Change-Id: Ic9e10dffb7a6d6e98990ae857a6765d300b00c49
parent dcfef627

system/gd/hci/le_address_manager.cc

+44 −4
Original line number Diff line number Diff line
@@ -19,6 +19,8 @@ 
#include <bluetooth/log.h>

#include <com_android_bluetooth_flags.h>



#include <ctime>



#include "hci/octets.h"

#include "include/macros.h"

#include "os/rand.h"
@@ -78,6 +80,12 @@ LeAddressManager::~LeAddressManager() { 
    address_rotation_non_wake_alarm_->Cancel();

    address_rotation_non_wake_alarm_.reset();

  }

  if (address_rotation_interval_min.has_value()) {

    address_rotation_interval_min.reset();

  }

  if (address_rotation_interval_max.has_value()) {

    address_rotation_interval_max.reset();

  }

}



// Called on initialization, and on IRK rotation
@@ -382,7 +390,8 @@ void LeAddressManager::prepare_to_rotate() { 


void LeAddressManager::schedule_rotate_random_address() {

  if (com::android::bluetooth::flags::non_wake_alarm_for_rpa_rotation()) {

    auto privateAddressIntervalRange = GetNextPrivateAddressIntervalRange();

    std::string client_name = "LeAddressManager";

    auto privateAddressIntervalRange = GetNextPrivateAddressIntervalRange(client_name);

    address_rotation_wake_alarm_->Schedule(

            common::BindOnce(

                    []() { log::info("deadline wakeup in schedule_rotate_random_address"); }),
@@ -390,6 +399,16 @@ void LeAddressManager::schedule_rotate_random_address() { 
    address_rotation_non_wake_alarm_->Schedule(

            common::BindOnce(&LeAddressManager::prepare_to_rotate, common::Unretained(this)),

            privateAddressIntervalRange.min);



    auto now = std::chrono::system_clock::now();

    if (address_rotation_interval_min.has_value()) {

      CheckAddressRotationHappenedInExpectedTimeInterval(

              *address_rotation_interval_min, *address_rotation_interval_max, now, client_name);

    }



    // Update the expected range here.

    address_rotation_interval_min.emplace(now + privateAddressIntervalRange.min);

    address_rotation_interval_max.emplace(now + privateAddressIntervalRange.max);

  } else {

    address_rotation_wake_alarm_->Schedule(

            common::BindOnce(&LeAddressManager::prepare_to_rotate, common::Unretained(this)),
@@ -513,7 +532,8 @@ std::chrono::milliseconds LeAddressManager::GetNextPrivateAddressIntervalMs() { 
  return minimum_rotation_time_ + random_ms;

}



PrivateAddressIntervalRange LeAddressManager::GetNextPrivateAddressIntervalRange() {

PrivateAddressIntervalRange LeAddressManager::GetNextPrivateAddressIntervalRange(

        const std::string& client_name) {

  // Get both alarms' delays as following:

  // - Non-wake  : Random between [minimum_rotation_time_, (minimum_rotation_time_ + 2 min)]

  // - Wake      : Random between [(maximum_rotation_time_ - 2 min), maximum_rotation_time_]
@@ -534,12 +554,32 @@ PrivateAddressIntervalRange LeAddressManager::GetNextPrivateAddressIntervalRange 
  auto min_seconds = std::chrono::duration_cast<std::chrono::seconds>(nonwake_delay - min_minutes);

  auto max_minutes = std::chrono::duration_cast<std::chrono::minutes>(wake_delay);

  auto max_seconds = std::chrono::duration_cast<std::chrono::seconds>(wake_delay - max_minutes);

  log::info("nonwake={}m{}s, wake={}m{}s", min_minutes.count(), min_seconds.count(),

            max_minutes.count(), max_seconds.count());

  log::info("client={}, nonwake={}m{}s, wake={}m{}s", client_name, min_minutes.count(),

            min_seconds.count(), max_minutes.count(), max_seconds.count());



  return PrivateAddressIntervalRange{nonwake_delay, wake_delay};

}



void LeAddressManager::CheckAddressRotationHappenedInExpectedTimeInterval(

        const std::chrono::time_point<std::chrono::system_clock>& interval_min,

        const std::chrono::time_point<std::chrono::system_clock>& interval_max,

        const std::chrono::time_point<std::chrono::system_clock>& event_time,

        const std::string& client_name) {

  // Give some tolerance to upper limit since alarms may ring a little bit late.

  auto upper_limit_tolerance = std::chrono::seconds(5);



  if (event_time < interval_min || event_time > interval_max + upper_limit_tolerance) {

    log::warn("RPA rotation happened outside expected time interval. client={}", client_name);



    auto tt_interval_min = std::chrono::system_clock::to_time_t(interval_min);

    auto tt_interval_max = std::chrono::system_clock::to_time_t(interval_max);

    auto tt_event_time = std::chrono::system_clock::to_time_t(event_time);

    log::warn("interval_min={}", ctime(&tt_interval_min));

    log::warn("interval_max={}", ctime(&tt_interval_max));

    log::warn("event_time=  {}", ctime(&tt_event_time));

  }

}



uint8_t LeAddressManager::GetFilterAcceptListSize() { return accept_list_size_; }



uint8_t LeAddressManager::GetResolvingListSize() { return resolving_list_size_; }

system/gd/hci/le_address_manager.h

+10 −1
Original line number Diff line number Diff line
@@ -98,7 +98,12 @@ public: 
  void ClearResolvingList();

  void OnCommandComplete(CommandCompleteView view);

  std::chrono::milliseconds GetNextPrivateAddressIntervalMs();

  PrivateAddressIntervalRange GetNextPrivateAddressIntervalRange();

  PrivateAddressIntervalRange GetNextPrivateAddressIntervalRange(const std::string& client_name);

  void CheckAddressRotationHappenedInExpectedTimeInterval(

          const std::chrono::time_point<std::chrono::system_clock>& interval_min,

          const std::chrono::time_point<std::chrono::system_clock>& interval_max,

          const std::chrono::time_point<std::chrono::system_clock>& event_time,

          const std::string& client_name);



  // Unsynchronized check for testing purposes

  size_t NumberCachedCommands() const { return cached_commands_.size(); }
@@ -177,6 +182,10 @@ private: 
  uint8_t resolving_list_size_;

  std::queue<Command> cached_commands_;

  bool supports_ble_privacy_{false};



  // Only used for logging error in address rotation time.

  std::optional<std::chrono::time_point<std::chrono::system_clock>> address_rotation_interval_min;

  std::optional<std::chrono::time_point<std::chrono::system_clock>> address_rotation_interval_max;

};



}  // namespace hci

system/gd/hci/le_advertising_manager.cc

+57 −3
Original line number Diff line number Diff line
@@ -88,6 +88,10 @@ struct Advertiser { 
  bool is_periodic = false;

  std::unique_ptr<os::Alarm> address_rotation_wake_alarm_;

  std::unique_ptr<os::Alarm> address_rotation_non_wake_alarm_;



  // Only used for logging error in address rotation time.

  std::optional<std::chrono::time_point<std::chrono::system_clock>> address_rotation_interval_min;

  std::optional<std::chrono::time_point<std::chrono::system_clock>> address_rotation_interval_max;

};



/**
@@ -318,6 +322,12 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 
      advertising_sets_[advertiser_id].address_rotation_non_wake_alarm_->Cancel();

      advertising_sets_[advertiser_id].address_rotation_non_wake_alarm_.reset();

    }

    if (advertising_sets_[advertiser_id].address_rotation_interval_min.has_value()) {

      advertising_sets_[advertiser_id].address_rotation_interval_min.reset();

    }

    if (advertising_sets_[advertiser_id].address_rotation_interval_max.has_value()) {

      advertising_sets_[advertiser_id].address_rotation_interval_max.reset();

    }



    enabled_sets_[advertiser_id].advertising_handle_ = kInvalidHandle;
@@ -359,8 +369,9 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 
            advertising_sets_[advertiser_id].address_rotation_non_wake_alarm_ =

                    std::make_unique<os::Alarm>(module_handler_, false);



            std::string client_name = "advertising_set_" + std::to_string(advertiser_id);

            auto privateAddressIntervalRange =

                    le_address_manager_->GetNextPrivateAddressIntervalRange();

                    le_address_manager_->GetNextPrivateAddressIntervalRange(client_name);



            advertising_sets_[advertiser_id].address_rotation_wake_alarm_->Schedule(

                    common::BindOnce(
@@ -370,6 +381,13 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 
                    common::BindOnce(&impl::set_advertising_set_random_address_on_timer,

                                     common::Unretained(this), advertiser_id),

                    privateAddressIntervalRange.min);



            // Update the expected range here.

            auto now = std::chrono::system_clock::now();

            advertising_sets_[advertiser_id].address_rotation_interval_min.emplace(

                    now + privateAddressIntervalRange.min);

            advertising_sets_[advertiser_id].address_rotation_interval_max.emplace(

                    now + privateAddressIntervalRange.max);

          } else {

            advertising_sets_[advertiser_id].address_rotation_wake_alarm_ =

                    std::make_unique<os::Alarm>(module_handler_);
@@ -643,8 +661,9 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 
          advertising_sets_[id].address_rotation_non_wake_alarm_ =

                  std::make_unique<os::Alarm>(module_handler_, false);



          std::string client_name = "advertising_set_" + std::to_string(id);

          auto privateAddressIntervalRange =

                  le_address_manager_->GetNextPrivateAddressIntervalRange();

                  le_address_manager_->GetNextPrivateAddressIntervalRange(client_name);



          advertising_sets_[id].address_rotation_wake_alarm_->Schedule(

                  common::BindOnce([]() {
@@ -655,6 +674,13 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 
                  common::BindOnce(&impl::set_advertising_set_random_address_on_timer,

                                   common::Unretained(this), id),

                  privateAddressIntervalRange.min);



          // Update the expected range here.

          auto now = std::chrono::system_clock::now();

          advertising_sets_[id].address_rotation_interval_min.emplace(

                  now + privateAddressIntervalRange.min);

          advertising_sets_[id].address_rotation_interval_max.emplace(

                  now + privateAddressIntervalRange.max);

        } else {

          advertising_sets_[id].address_rotation_wake_alarm_ =

                  std::make_unique<os::Alarm>(module_handler_);
@@ -762,6 +788,12 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 
        advertising_sets_[advertiser_id].address_rotation_non_wake_alarm_->Cancel();

        advertising_sets_[advertiser_id].address_rotation_non_wake_alarm_.reset();

      }

      if (advertising_sets_[advertiser_id].address_rotation_interval_min.has_value()) {

        advertising_sets_[advertiser_id].address_rotation_interval_min.reset();

      }

      if (advertising_sets_[advertiser_id].address_rotation_interval_max.has_value()) {

        advertising_sets_[advertiser_id].address_rotation_interval_max.reset();

      }

      return;

    }
@@ -796,7 +828,9 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 


    log::info("Scheduling address rotation for advertiser_id={}", advertiser_id);

    if (com::android::bluetooth::flags::non_wake_alarm_for_rpa_rotation()) {

      auto privateAddressIntervalRange = le_address_manager_->GetNextPrivateAddressIntervalRange();

      std::string client_name = "advertising_set_" + std::to_string(advertiser_id);

      auto privateAddressIntervalRange =

              le_address_manager_->GetNextPrivateAddressIntervalRange(client_name);

      advertising_sets_[advertiser_id].address_rotation_wake_alarm_->Schedule(

              common::BindOnce([]() {

                log::info("deadline wakeup in set_advertising_set_random_address_on_timer");
@@ -806,6 +840,20 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 
              common::BindOnce(&impl::set_advertising_set_random_address_on_timer,

                               common::Unretained(this), advertiser_id),

              privateAddressIntervalRange.min);



      auto now = std::chrono::system_clock::now();

      if (advertising_sets_[advertiser_id].address_rotation_interval_min.has_value()) {

        le_address_manager_->CheckAddressRotationHappenedInExpectedTimeInterval(

                *(advertising_sets_[advertiser_id].address_rotation_interval_min),

                *(advertising_sets_[advertiser_id].address_rotation_interval_max), now,

                client_name);

      }



      // Update the expected range here.

      advertising_sets_[advertiser_id].address_rotation_interval_min.emplace(

              now + privateAddressIntervalRange.min);

      advertising_sets_[advertiser_id].address_rotation_interval_max.emplace(

              now + privateAddressIntervalRange.max);

    } else {

      advertising_sets_[advertiser_id].address_rotation_wake_alarm_->Schedule(

              common::BindOnce(&impl::set_advertising_set_random_address_on_timer,
@@ -1230,6 +1278,12 @@ struct LeAdvertisingManager::impl : public bluetooth::hci::LeAddressManagerCallb 
        advertising_sets_[advertiser_id].address_rotation_non_wake_alarm_->Cancel();

        advertising_sets_[advertiser_id].address_rotation_non_wake_alarm_.reset();

      }

      if (advertising_sets_[advertiser_id].address_rotation_interval_min.has_value()) {

        advertising_sets_[advertiser_id].address_rotation_interval_min.reset();

      }

      if (advertising_sets_[advertiser_id].address_rotation_interval_max.has_value()) {

        advertising_sets_[advertiser_id].address_rotation_interval_max.reset();

      }

    }

  }