Merge "Format time when print stopwatch log." (e3a8ee69) · Commits · e / os / android_packages_modules_Bluetooth

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__]++;
		}