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

Commit 8a196bc1 authored by Treehugger Robot's avatar Treehugger Robot Committed by Gerrit Code Review
Browse files

Merge "stopwatch: improve stopwatch problems"

parents e59c2640 627a6def

system/common/stop_watch_legacy.cc

+16 −1
Original line number Original line Diff line number Diff line
@@ -19,6 +19,7 @@ 
#include "common/stop_watch_legacy.h"

#include "common/stop_watch_legacy.h"





#include <iomanip>

#include <iomanip>

#include <mutex>

#include <sstream>

#include <sstream>

#include <utility>

#include <utility>
@@ -31,16 +32,29 @@ namespace common { 
static const int LOG_BUFFER_LENGTH = 10;

static const int LOG_BUFFER_LENGTH = 10;

static std::array<StopWatchLog, LOG_BUFFER_LENGTH> stopwatch_logs;

static std::array<StopWatchLog, LOG_BUFFER_LENGTH> stopwatch_logs;

static int current_buffer_index;

static int current_buffer_index;

static std::recursive_mutex stopwatch_log_mutex;





void StopWatchLegacy::RecordLog(StopWatchLog log) {

void StopWatchLegacy::RecordLog(StopWatchLog log) {

  std::unique_lock<std::recursive_mutex> lock(stopwatch_log_mutex, std::defer_lock);

  if (!lock.try_lock()) {

    LOG_INFO("try_lock fail. log content: %s, took %zu us", log.message.c_str(),

             static_cast<size_t>(

                 std::chrono::duration_cast<std::chrono::microseconds>(

                     stopwatch_logs[current_buffer_index].end_timestamp -

                     stopwatch_logs[current_buffer_index].start_timestamp)

                     .count()));

    return;

  }

  if (current_buffer_index >= LOG_BUFFER_LENGTH) {

  if (current_buffer_index >= LOG_BUFFER_LENGTH) {

    current_buffer_index = 0;

    current_buffer_index = 0;

  }

  }

  stopwatch_logs[current_buffer_index] = std::move(log);

  stopwatch_logs[current_buffer_index] = std::move(log);

  current_buffer_index++;

  current_buffer_index++;

  lock.unlock();

}

}





void StopWatchLegacy::DumpStopWatchLog() {

void StopWatchLegacy::DumpStopWatchLog() {

  std::lock_guard<std::recursive_mutex> lock(stopwatch_log_mutex);

  LOG_INFO("=-----------------------------------=");

  LOG_INFO("=-----------------------------------=");

  LOG_INFO("bluetooth stopwatch log history:");

  LOG_INFO("bluetooth stopwatch log history:");

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

  for (int i = 0; i < LOG_BUFFER_LENGTH; i++) {
@@ -48,7 +62,8 @@ void StopWatchLegacy::DumpStopWatchLog() { 
      current_buffer_index = 0;

      current_buffer_index = 0;

    }

    }

    if (stopwatch_logs[current_buffer_index].message.empty()) {

    if (stopwatch_logs[current_buffer_index].message.empty()) {

      break;

      current_buffer_index++;

      continue;

    }

    }

    std::stringstream ss;

    std::stringstream ss;

    auto now = stopwatch_logs[current_buffer_index].timestamp;

    auto now = stopwatch_logs[current_buffer_index].timestamp;

system/gd/common/stop_watch.cc

+16 −1
Original line number Original line Diff line number Diff line
@@ -19,6 +19,7 @@ 
#include "common/stop_watch.h"

#include "common/stop_watch.h"





#include <iomanip>

#include <iomanip>

#include <mutex>

#include <sstream>

#include <sstream>

#include <utility>

#include <utility>
@@ -31,16 +32,29 @@ namespace common { 
static const int LOG_BUFFER_LENGTH = 10;

static const int LOG_BUFFER_LENGTH = 10;

static std::array<StopWatchLog, LOG_BUFFER_LENGTH> stopwatch_logs;

static std::array<StopWatchLog, LOG_BUFFER_LENGTH> stopwatch_logs;

static int current_buffer_index;

static int current_buffer_index;

static std::recursive_mutex stopwatch_log_mutex;





void StopWatch::RecordLog(StopWatchLog log) {

void StopWatch::RecordLog(StopWatchLog log) {

  std::unique_lock<std::recursive_mutex> lock(stopwatch_log_mutex, std::defer_lock);

  if (!lock.try_lock()) {

    LOG_INFO("try_lock fail. log content: %s, took %zu us", log.message.c_str(),

             static_cast<size_t>(

                 std::chrono::duration_cast<std::chrono::microseconds>(

                     stopwatch_logs[current_buffer_index].end_timestamp -

                     stopwatch_logs[current_buffer_index].start_timestamp)

                     .count()));

    return;

  }

  if (current_buffer_index >= LOG_BUFFER_LENGTH) {

  if (current_buffer_index >= LOG_BUFFER_LENGTH) {

    current_buffer_index = 0;

    current_buffer_index = 0;

  }

  }

  stopwatch_logs[current_buffer_index] = std::move(log);

  stopwatch_logs[current_buffer_index] = std::move(log);

  current_buffer_index++;

  current_buffer_index++;

  lock.unlock();

}

}





void StopWatch::DumpStopWatchLog() {

void StopWatch::DumpStopWatchLog() {

  std::lock_guard<std::recursive_mutex> lock(stopwatch_log_mutex);

  LOG_INFO("=-----------------------------------=");

  LOG_INFO("=-----------------------------------=");

  LOG_INFO("bluetooth stopwatch log history:");

  LOG_INFO("bluetooth stopwatch log history:");

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

  for (int i = 0; i < LOG_BUFFER_LENGTH; i++) {
@@ -48,7 +62,8 @@ void StopWatch::DumpStopWatchLog() { 
      current_buffer_index = 0;

      current_buffer_index = 0;

    }

    }

    if (stopwatch_logs[current_buffer_index].message.empty()) {

    if (stopwatch_logs[current_buffer_index].message.empty()) {

      break;

      current_buffer_index++;

      continue;

    }

    }

    std::stringstream ss;

    std::stringstream ss;

    auto now = stopwatch_logs[current_buffer_index].timestamp;

    auto now = stopwatch_logs[current_buffer_index].timestamp;

system/gd/hal/hci_hal_android_hidl.cc

+1 −0
Original line number Original line Diff line number Diff line
@@ -83,6 +83,7 @@ class InternalHciCallbacks : public IBluetoothHciCallbacks { 
  }

  }





  Return<void> initializationComplete(HidlStatus status) {

  Return<void> initializationComplete(HidlStatus status) {

    common::StopWatch(__func__);

    ASSERT(status == HidlStatus::SUCCESS);

    ASSERT(status == HidlStatus::SUCCESS);

    init_promise_->set_value();

    init_promise_->set_value();

    return Void();

    return Void();

system/gd/hci/hci_layer.cc

+2 −0
Original line number Original line Diff line number Diff line
@@ -18,6 +18,7 @@ 




#include "common/bind.h"

#include "common/bind.h"

#include "common/init_flags.h"

#include "common/init_flags.h"

#include "common/stop_watch.h"

#include "hci/hci_metrics_logging.h"

#include "hci/hci_metrics_logging.h"

#include "os/alarm.h"

#include "os/alarm.h"

#include "os/metrics.h"

#include "os/metrics.h"
@@ -181,6 +182,7 @@ struct HciLayer::impl { 
  }

  }





  void on_hci_timeout(OpCode op_code) {

  void on_hci_timeout(OpCode op_code) {

    common::StopWatch::DumpStopWatchLog();

    LOG_ERROR("Timed out waiting for 0x%02hx (%s)", op_code, OpCodeText(op_code).c_str());

    LOG_ERROR("Timed out waiting for 0x%02hx (%s)", op_code, OpCodeText(op_code).c_str());

    // TODO: LogMetricHciTimeoutEvent(static_cast<uint32_t>(op_code));

    // TODO: LogMetricHciTimeoutEvent(static_cast<uint32_t>(op_code));

system/hci/src/hci_layer.cc

+5 −0
Original line number Original line Diff line number Diff line
@@ -42,6 +42,7 @@ 
#include "common/message_loop_thread.h"

#include "common/message_loop_thread.h"

#include "common/metrics.h"

#include "common/metrics.h"

#include "common/once_timer.h"

#include "common/once_timer.h"

#include "common/stop_watch_legacy.h"

#include "hci_inject.h"

#include "hci_inject.h"

#include "hci_internals.h"

#include "hci_internals.h"

#include "hcidefs.h"

#include "hcidefs.h"
@@ -58,6 +59,7 @@ 




using bluetooth::common::MessageLoopThread;

using bluetooth::common::MessageLoopThread;

using bluetooth::common::OnceTimer;

using bluetooth::common::OnceTimer;

using bluetooth::common::StopWatchLegacy;





extern void hci_initialize();

extern void hci_initialize();

extern void hci_transmit(BT_HDR* packet);

extern void hci_transmit(BT_HDR* packet);
@@ -376,6 +378,8 @@ static void event_finish_startup(UNUSED_ATTR void* context) { 
static void startup_timer_expired(UNUSED_ATTR void* context) {

static void startup_timer_expired(UNUSED_ATTR void* context) {

  LOG_ERROR("%s", __func__);

  LOG_ERROR("%s", __func__);





  StopWatchLegacy::DumpStopWatchLog();



  LOG_EVENT_INT(BT_HCI_TIMEOUT_TAG_NUM, HCI_STARTUP_TIMED_OUT);

  LOG_EVENT_INT(BT_HCI_TIMEOUT_TAG_NUM, HCI_STARTUP_TIMED_OUT);





  hci_close();

  hci_close();
@@ -522,6 +526,7 @@ static void command_timed_out_log_info(void* original_wait_entry) { 
// Print debugging information and quit. Don't dereference original_wait_entry.

// Print debugging information and quit. Don't dereference original_wait_entry.

static void command_timed_out(void* original_wait_entry) {

static void command_timed_out(void* original_wait_entry) {

  LOG_ERROR("%s", __func__);

  LOG_ERROR("%s", __func__);

  StopWatchLegacy::DumpStopWatchLog();

  std::unique_lock<std::recursive_timed_mutex> lock(

  std::unique_lock<std::recursive_timed_mutex> lock(

      commands_pending_response_mutex, std::defer_lock);

      commands_pending_response_mutex, std::defer_lock);

  if (!lock.try_lock_for(std::chrono::milliseconds(

  if (!lock.try_lock_for(std::chrono::milliseconds(