1 /*
2 * Copyright 2020 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #define LOG_TAG "BtStopWatch"
18
19 #include "common/stop_watch.h"
20
21 #include <bluetooth/log.h>
22
23 #include <iomanip>
24 #include <mutex>
25 #include <sstream>
26 #include <utility>
27
28 #include "common/init_flags.h"
29 #include "os/log.h"
30
31 namespace bluetooth {
32 namespace common {
33
34 static const int LOG_BUFFER_LENGTH = 10;
35 static std::array<StopWatchLog, LOG_BUFFER_LENGTH> stopwatch_logs;
36 static int current_buffer_index;
37 static std::recursive_mutex stopwatch_log_mutex;
38
RecordLog(StopWatchLog log)39 void StopWatch::RecordLog(StopWatchLog log) {
40 std::unique_lock<std::recursive_mutex> lock(stopwatch_log_mutex, std::defer_lock);
41 if (!lock.try_lock()) {
42 log::info(
43 "try_lock fail. log content: {}, took {} us",
44 log.message,
45 static_cast<size_t>(std::chrono::duration_cast<std::chrono::microseconds>(
46 stopwatch_logs[current_buffer_index].end_timestamp -
47 stopwatch_logs[current_buffer_index].start_timestamp)
48 .count()));
49 return;
50 }
51 if (current_buffer_index >= LOG_BUFFER_LENGTH) {
52 current_buffer_index = 0;
53 }
54 stopwatch_logs[current_buffer_index] = std::move(log);
55 current_buffer_index++;
56 lock.unlock();
57 }
58
DumpStopWatchLog()59 void StopWatch::DumpStopWatchLog() {
60 std::lock_guard<std::recursive_mutex> lock(stopwatch_log_mutex);
61 log::info("=-----------------------------------=");
62 log::info("bluetooth stopwatch log history:");
63 for (int i = 0; i < LOG_BUFFER_LENGTH; i++) {
64 if (current_buffer_index >= LOG_BUFFER_LENGTH) {
65 current_buffer_index = 0;
66 }
67 if (stopwatch_logs[current_buffer_index].message.empty()) {
68 current_buffer_index++;
69 continue;
70 }
71 std::stringstream ss;
72 auto now = stopwatch_logs[current_buffer_index].timestamp;
73 auto millis = std::chrono::duration_cast<std::chrono::milliseconds>(
74 now.time_since_epoch()) %
75 1000;
76 auto now_time_t = std::chrono::system_clock::to_time_t(now);
77 ss << std::put_time(std::localtime(&now_time_t), "%Y-%m-%d %H:%M:%S");
78 ss << '.' << std::setfill('0') << std::setw(3) << millis.count();
79 std::string start_timestamp = ss.str();
80 log::info(
81 "{}: {}: took {} us",
82 start_timestamp,
83 stopwatch_logs[current_buffer_index].message,
84 static_cast<size_t>(std::chrono::duration_cast<std::chrono::microseconds>(
85 stopwatch_logs[current_buffer_index].end_timestamp -
86 stopwatch_logs[current_buffer_index].start_timestamp)
87 .count()));
88 current_buffer_index++;
89 }
90 log::info("=-----------------------------------=");
91 }
92
StopWatch(std::string text)93 StopWatch::StopWatch(std::string text)
94 : text_(std::move(text)),
95 timestamp_(std::chrono::system_clock::now()),
96 start_timestamp_(std::chrono::high_resolution_clock::now()) {}
97
~StopWatch()98 StopWatch::~StopWatch() {
99 StopWatchLog sw_log;
100 sw_log.timestamp = timestamp_;
101 sw_log.start_timestamp = start_timestamp_;
102 sw_log.end_timestamp = std::chrono::high_resolution_clock::now();
103 sw_log.message = std::move(text_);
104
105 RecordLog(std::move(sw_log));
106 }
107
108 } // namespace common
109 } // namespace bluetooth
110