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

Commit f9464be4 authored by weichinweng's avatar weichinweng
Browse files

Format time when print stopwatch log. 

Bug: 187902405
Test: atest BluetoothInstrumentationTests
Tag: #feature
Change-Id: I26f7a334218b303a46693c5dbfa309725b9e8d7b
parent 56703993

system/common/stop_watch_legacy.cc

+28 −23
Original line number Diff line number Diff line
@@ -29,10 +29,10 @@ namespace bluetooth { 
namespace common {



static const int LOG_BUFFER_LENGTH = 10;

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

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

static int current_buffer_index;



void StopWatchLegacy::RecordLog(std::string log) {

void StopWatchLegacy::RecordLog(StopWatchLog log) {

  if (current_buffer_index >= LOG_BUFFER_LENGTH) {

    current_buffer_index = 0;

  }
@@ -47,38 +47,43 @@ void StopWatchLegacy::DumpStopWatchLog() { 
    if (current_buffer_index >= LOG_BUFFER_LENGTH) {

      current_buffer_index = 0;

    }

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

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

      break;

    }

    LOG_INFO("%s", stopwatch_logs[current_buffer_index].c_str());

    current_buffer_index++;

  }

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

}



StopWatchLegacy::StopWatchLegacy(std::string text)

    : text_(std::move(text)),

      start_time_(std::chrono::high_resolution_clock::now()) {

    std::stringstream ss;

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

    auto now = stopwatch_logs[current_buffer_index].timestamp;

    auto millis = std::chrono::duration_cast<std::chrono::milliseconds>(

                      now.time_since_epoch()) %

                  1000;

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

    ss << std::put_time(std::localtime(&now_time_t), "%Y-%m-%d %H:%M:%S");

    ss << '.' << std::setfill('0') << std::setw(3) << millis.count();

  start_timestamp_ = ss.str();



  RecordLog(start_timestamp_ + ": " + text_);

    std::string start_timestamp = ss.str();

    LOG_INFO("%s: %s: took %zu us", start_timestamp.c_str(),

             stopwatch_logs[current_buffer_index].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()));

    current_buffer_index++;

  }

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

}



StopWatchLegacy::StopWatchLegacy(std::string text)

    : text_(std::move(text)),

      timestamp_(std::chrono::system_clock::now()),

      start_timestamp_(std::chrono::high_resolution_clock::now()) {}



StopWatchLegacy::~StopWatchLegacy() {

  RecordLog(start_timestamp_ + ": " + text_ + ": took " +

            std::to_string(static_cast<size_t>(

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

                    std::chrono::high_resolution_clock::now() - start_time_)

                    .count())) +

            " us");

  StopWatchLog sw_log;

  sw_log.timestamp = timestamp_;

  sw_log.start_timestamp = start_timestamp_;

  sw_log.end_timestamp = std::chrono::high_resolution_clock::now();

  sw_log.message = std::move(text_);



  RecordLog(std::move(sw_log));

}



}  // namespace common

system/common/stop_watch_legacy.h

+10 −3
Original line number Diff line number Diff line
@@ -22,6 +22,13 @@ 
namespace bluetooth {

namespace common {



typedef struct {

  std::chrono::system_clock::time_point timestamp;

  std::chrono::high_resolution_clock::time_point start_timestamp;

  std::chrono::high_resolution_clock::time_point end_timestamp;

  std::string message;

} StopWatchLog;



class StopWatchLegacy {

 public:

  static void DumpStopWatchLog(void);
@@ -30,9 +37,9 @@ class StopWatchLegacy { 


 private:

  std::string text_;

  std::chrono::time_point<std::chrono::high_resolution_clock> start_time_;

  std::string start_timestamp_;

  void RecordLog(std::string log);

  std::chrono::system_clock::time_point timestamp_;

  std::chrono::high_resolution_clock::time_point start_timestamp_;

  void RecordLog(StopWatchLog log);

};



}  // namespace common

system/gd/common/stop_watch.cc

+30 −21
Original line number Diff line number Diff line
@@ -29,10 +29,10 @@ namespace bluetooth { 
namespace common {



static const int LOG_BUFFER_LENGTH = 10;

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

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

static int current_buffer_index;



void StopWatch::RecordLog(std::string log) {

void StopWatch::RecordLog(StopWatchLog log) {

  if (current_buffer_index >= LOG_BUFFER_LENGTH) {

    current_buffer_index = 0;

  }
@@ -47,35 +47,44 @@ void StopWatch::DumpStopWatchLog() { 
    if (current_buffer_index >= LOG_BUFFER_LENGTH) {

      current_buffer_index = 0;

    }

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

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

      break;

    }

    LOG_DEBUG("%s", stopwatch_logs[current_buffer_index].c_str());

    std::stringstream ss;

    auto now = stopwatch_logs[current_buffer_index].timestamp;

    auto millis = std::chrono::duration_cast<std::chrono::milliseconds>(

                      now.time_since_epoch()) %

                  1000;

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

    ss << std::put_time(std::localtime(&now_time_t), "%Y-%m-%d %H:%M:%S");

    ss << '.' << std::setfill('0') << std::setw(3) << millis.count();

    std::string start_timestamp = ss.str();

    LOG_INFO(

        "%s: %s: took %zu us",

        start_timestamp.c_str(),

        stopwatch_logs[current_buffer_index].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()));

    current_buffer_index++;

  }

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

}



StopWatch::StopWatch(std::string text)

    : text_(std::move(text)), start_time_(std::chrono::high_resolution_clock::now()) {

  std::stringstream ss;

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

  auto millis = std::chrono::duration_cast<std::chrono::milliseconds>(now.time_since_epoch()) % 1000;

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

  ss << std::put_time(std::localtime(&now_time_t), "%Y-%m-%d %H:%M:%S");

  ss << '.' << std::setfill('0') << std::setw(3) << millis.count();

  start_timestamp_ = ss.str();



  RecordLog(start_timestamp_ + ": " + text_);

}

    : text_(std::move(text)),

      timestamp_(std::chrono::system_clock::now()),

      start_timestamp_(std::chrono::high_resolution_clock::now()) {}



StopWatch::~StopWatch() {

  RecordLog(

      start_timestamp_ + ": " + text_ + ": took " +

      std::to_string(static_cast<size_t>(

          std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::high_resolution_clock::now() - start_time_)

              .count())) +

      " us");

  StopWatchLog sw_log;

  sw_log.timestamp = timestamp_;

  sw_log.start_timestamp = start_timestamp_;

  sw_log.end_timestamp = std::chrono::high_resolution_clock::now();

  sw_log.message = std::move(text_);



  RecordLog(std::move(sw_log));

}



}  // namespace common

system/gd/common/stop_watch.h

+10 −3
Original line number Diff line number Diff line
@@ -22,6 +22,13 @@ 
namespace bluetooth {

namespace common {



typedef struct {

  std::chrono::system_clock::time_point timestamp;

  std::chrono::high_resolution_clock::time_point start_timestamp;

  std::chrono::high_resolution_clock::time_point end_timestamp;

  std::string message;

} StopWatchLog;



class StopWatch {

 public:

  static void DumpStopWatchLog(void);
@@ -30,9 +37,9 @@ class StopWatch { 


 private:

  std::string text_;

  std::chrono::time_point<std::chrono::high_resolution_clock> start_time_;

  std::string start_timestamp_;

  void RecordLog(std::string log);

  std::chrono::system_clock::time_point timestamp_;

  std::chrono::high_resolution_clock::time_point start_timestamp_;

  void RecordLog(StopWatchLog log);

};



}  // namespace common

system/test/mock/mock_common_stop_watch_legacy.cc

+3 −2
Original line number Diff line number Diff line
@@ -40,14 +40,15 @@ namespace common { 


StopWatchLegacy::StopWatchLegacy(std::string text)

    : text_(std::move(text)),

      start_time_(std::chrono::high_resolution_clock::now()) {

      timestamp_(std::chrono::system_clock::now()),

      start_timestamp_(std::chrono::high_resolution_clock::now()) {

  mock_function_count_map[__func__]++;

}

StopWatchLegacy::~StopWatchLegacy() { mock_function_count_map[__func__]++; }

void StopWatchLegacy::DumpStopWatchLog() {

  mock_function_count_map[__func__]++;

}

void StopWatchLegacy::RecordLog(std::string log) {

void StopWatchLegacy::RecordLog(StopWatchLog log) {

  mock_function_count_map[__func__]++;

}