1 /******************************************************************************
2  *
3  *  Copyright 2015 Google, Inc.
4  *
5  *  Licensed under the Apache License, Version 2.0 (the "License");
6  *  you may not use this file except in compliance with the License.
7  *  You may obtain a copy of the License at:
8  *
9  *  http://www.apache.org/licenses/LICENSE-2.0
10  *
11  *  Unless required by applicable law or agreed to in writing, software
12  *  distributed under the License is distributed on an "AS IS" BASIS,
13  *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14  *  See the License for the specific language governing permissions and
15  *  limitations under the License.
16  *
17  ******************************************************************************/
18 
19 #define LOG_TAG "bt_osi_wakelock"
20 
21 #include <errno.h>
22 #include <fcntl.h>
23 #include <hardware/bluetooth.h>
24 #include <inttypes.h>
25 #include <limits.h>
26 #include <pthread.h>
27 #include <string.h>
28 #include <sys/stat.h>
29 #include <sys/types.h>
30 #include <time.h>
31 #include <unistd.h>
32 
33 #include <mutex>
34 #include <string>
35 
36 #include "base/logging.h"
37 #include "common/metrics.h"
38 #include "osi/include/alarm.h"
39 #include "osi/include/allocator.h"
40 #include "osi/include/log.h"
41 #include "osi/include/osi.h"
42 #include "osi/include/thread.h"
43 #include "osi/include/wakelock.h"
44 
45 using bluetooth::common::BluetoothMetricsLogger;
46 
47 static bt_os_callouts_t* wakelock_os_callouts = NULL;
48 static bool is_native = true;
49 
50 static const clockid_t CLOCK_ID = CLOCK_BOOTTIME;
51 static const char* WAKE_LOCK_ID = "bluetooth_timer";
52 static const std::string DEFAULT_WAKE_LOCK_PATH = "/sys/power/wake_lock";
53 static const std::string DEFAULT_WAKE_UNLOCK_PATH = "/sys/power/wake_unlock";
54 static std::string wake_lock_path;
55 static std::string wake_unlock_path;
56 static ssize_t locked_id_len = -1;
57 static pthread_once_t initialized = PTHREAD_ONCE_INIT;
58 static int wake_lock_fd = INVALID_FD;
59 static int wake_unlock_fd = INVALID_FD;
60 
61 // Wakelock statistics for the "bluetooth_timer"
62 typedef struct {
63   bool is_acquired;
64   size_t acquired_count;
65   size_t released_count;
66   size_t acquired_errors;
67   size_t released_errors;
68   uint64_t min_acquired_interval_ms;
69   uint64_t max_acquired_interval_ms;
70   uint64_t last_acquired_interval_ms;
71   uint64_t total_acquired_interval_ms;
72   uint64_t last_acquired_timestamp_ms;
73   uint64_t last_released_timestamp_ms;
74   uint64_t last_reset_timestamp_ms;
75   int last_acquired_error;
76   int last_released_error;
77 } wakelock_stats_t;
78 
79 static wakelock_stats_t wakelock_stats;
80 
81 // This mutex ensures that the functions that update and dump the statistics
82 // are executed serially.
83 static std::mutex stats_mutex;
84 
85 static bt_status_t wakelock_acquire_callout(void);
86 static bt_status_t wakelock_acquire_native(void);
87 static bt_status_t wakelock_release_callout(void);
88 static bt_status_t wakelock_release_native(void);
89 static void wakelock_initialize(void);
90 static void wakelock_initialize_native(void);
91 static void reset_wakelock_stats(void);
92 static void update_wakelock_acquired_stats(bt_status_t acquired_status);
93 static void update_wakelock_released_stats(bt_status_t released_status);
94 
wakelock_set_os_callouts(bt_os_callouts_t * callouts)95 void wakelock_set_os_callouts(bt_os_callouts_t* callouts) {
96   wakelock_os_callouts = callouts;
97   is_native = (wakelock_os_callouts == NULL);
98   LOG_INFO("%s set to %s", __func__, (is_native) ? "native" : "non-native");
99 }
100 
wakelock_acquire(void)101 bool wakelock_acquire(void) {
102   pthread_once(&initialized, wakelock_initialize);
103 
104   bt_status_t status = BT_STATUS_FAIL;
105 
106   if (is_native)
107     status = wakelock_acquire_native();
108   else
109     status = wakelock_acquire_callout();
110 
111   update_wakelock_acquired_stats(status);
112 
113   if (status != BT_STATUS_SUCCESS)
114     LOG_ERROR("%s unable to acquire wake lock: %d", __func__, status);
115 
116   return (status == BT_STATUS_SUCCESS);
117 }
118 
wakelock_acquire_callout(void)119 static bt_status_t wakelock_acquire_callout(void) {
120   return static_cast<bt_status_t>(
121       wakelock_os_callouts->acquire_wake_lock(WAKE_LOCK_ID));
122 }
123 
wakelock_acquire_native(void)124 static bt_status_t wakelock_acquire_native(void) {
125   if (wake_lock_fd == INVALID_FD) {
126     LOG_ERROR("%s lock not acquired, invalid fd", __func__);
127     return BT_STATUS_PARM_INVALID;
128   }
129 
130   if (wake_unlock_fd == INVALID_FD) {
131     LOG_ERROR("%s not acquiring lock: can't release lock", __func__);
132     return BT_STATUS_PARM_INVALID;
133   }
134 
135   long lock_name_len = strlen(WAKE_LOCK_ID);
136   locked_id_len = write(wake_lock_fd, WAKE_LOCK_ID, lock_name_len);
137   if (locked_id_len == -1) {
138     LOG_ERROR("%s wake lock not acquired: %s", __func__, strerror(errno));
139     return BT_STATUS_FAIL;
140   } else if (locked_id_len < lock_name_len) {
141     // TODO (jamuraa): this is weird. maybe we should release and retry.
142     LOG_WARN("%s wake lock truncated to %zd chars", __func__, locked_id_len);
143   }
144   return BT_STATUS_SUCCESS;
145 }
146 
wakelock_release(void)147 bool wakelock_release(void) {
148   pthread_once(&initialized, wakelock_initialize);
149 
150   bt_status_t status = BT_STATUS_FAIL;
151 
152   if (is_native)
153     status = wakelock_release_native();
154   else
155     status = wakelock_release_callout();
156 
157   update_wakelock_released_stats(status);
158 
159   return (status == BT_STATUS_SUCCESS);
160 }
161 
wakelock_release_callout(void)162 static bt_status_t wakelock_release_callout(void) {
163   return static_cast<bt_status_t>(
164       wakelock_os_callouts->release_wake_lock(WAKE_LOCK_ID));
165 }
166 
wakelock_release_native(void)167 static bt_status_t wakelock_release_native(void) {
168   if (wake_unlock_fd == INVALID_FD) {
169     LOG_ERROR("%s lock not released, invalid fd", __func__);
170     return BT_STATUS_PARM_INVALID;
171   }
172 
173   ssize_t wrote_name_len = write(wake_unlock_fd, WAKE_LOCK_ID, locked_id_len);
174   if (wrote_name_len == -1) {
175     LOG_ERROR("%s can't release wake lock: %s", __func__, strerror(errno));
176   } else if (wrote_name_len < locked_id_len) {
177     LOG_ERROR("%s lock release only wrote %zd, assuming released", __func__,
178               wrote_name_len);
179   }
180   return BT_STATUS_SUCCESS;
181 }
182 
wakelock_initialize(void)183 static void wakelock_initialize(void) {
184   reset_wakelock_stats();
185 
186   if (is_native) wakelock_initialize_native();
187 }
188 
wakelock_initialize_native(void)189 static void wakelock_initialize_native(void) {
190   LOG_DEBUG("%s opening wake locks", __func__);
191 
192   if (wake_lock_path.empty()) wake_lock_path = DEFAULT_WAKE_LOCK_PATH;
193 
194   wake_lock_fd = open(wake_lock_path.c_str(), O_RDWR | O_CLOEXEC);
195   if (wake_lock_fd == INVALID_FD) {
196     LOG_ERROR("%s can't open wake lock %s: %s", __func__,
197               wake_lock_path.c_str(), strerror(errno));
198     CHECK(wake_lock_fd != INVALID_FD);
199   }
200 
201   if (wake_unlock_path.empty()) wake_unlock_path = DEFAULT_WAKE_UNLOCK_PATH;
202 
203   wake_unlock_fd = open(wake_unlock_path.c_str(), O_RDWR | O_CLOEXEC);
204   if (wake_unlock_fd == INVALID_FD) {
205     LOG_ERROR("%s can't open wake unlock %s: %s", __func__,
206               wake_unlock_path.c_str(), strerror(errno));
207     CHECK(wake_unlock_fd != INVALID_FD);
208   }
209 }
210 
wakelock_cleanup(void)211 void wakelock_cleanup(void) {
212   if (wakelock_stats.is_acquired) {
213     LOG_ERROR("%s releasing wake lock as part of cleanup", __func__);
214     wakelock_release();
215   }
216   wake_lock_path.clear();
217   wake_unlock_path.clear();
218   initialized = PTHREAD_ONCE_INIT;
219 }
220 
wakelock_set_paths(const char * lock_path,const char * unlock_path)221 void wakelock_set_paths(const char* lock_path, const char* unlock_path) {
222   if (lock_path) wake_lock_path = lock_path;
223 
224   if (unlock_path) wake_unlock_path = unlock_path;
225 }
226 
now_ms(void)227 static uint64_t now_ms(void) {
228   struct timespec ts;
229   if (clock_gettime(CLOCK_ID, &ts) == -1) {
230     LOG_ERROR("%s unable to get current time: %s", __func__, strerror(errno));
231     return 0;
232   }
233 
234   return (ts.tv_sec * 1000LL) + (ts.tv_nsec / 1000000LL);
235 }
236 
237 // Reset the Bluetooth wakelock statistics.
238 // This function is thread-safe.
reset_wakelock_stats(void)239 static void reset_wakelock_stats(void) {
240   std::lock_guard<std::mutex> lock(stats_mutex);
241 
242   wakelock_stats.is_acquired = false;
243   wakelock_stats.acquired_count = 0;
244   wakelock_stats.released_count = 0;
245   wakelock_stats.acquired_errors = 0;
246   wakelock_stats.released_errors = 0;
247   wakelock_stats.min_acquired_interval_ms = 0;
248   wakelock_stats.max_acquired_interval_ms = 0;
249   wakelock_stats.last_acquired_interval_ms = 0;
250   wakelock_stats.total_acquired_interval_ms = 0;
251   wakelock_stats.last_acquired_timestamp_ms = 0;
252   wakelock_stats.last_released_timestamp_ms = 0;
253   wakelock_stats.last_reset_timestamp_ms = now_ms();
254 }
255 
256 //
257 // Update the Bluetooth acquire wakelock statistics.
258 //
259 // This function should be called every time when the wakelock is acquired.
260 // |acquired_status| is the status code that was return when the wakelock was
261 // acquired.
262 // This function is thread-safe.
263 //
update_wakelock_acquired_stats(bt_status_t acquired_status)264 static void update_wakelock_acquired_stats(bt_status_t acquired_status) {
265   const uint64_t just_now_ms = now_ms();
266 
267   std::lock_guard<std::mutex> lock(stats_mutex);
268 
269   if (acquired_status != BT_STATUS_SUCCESS) {
270     wakelock_stats.acquired_errors++;
271     wakelock_stats.last_acquired_error = acquired_status;
272   }
273 
274   if (wakelock_stats.is_acquired) {
275     return;
276   }
277 
278   wakelock_stats.is_acquired = true;
279   wakelock_stats.acquired_count++;
280   wakelock_stats.last_acquired_timestamp_ms = just_now_ms;
281 
282   BluetoothMetricsLogger::GetInstance()->LogWakeEvent(
283       bluetooth::common::WAKE_EVENT_ACQUIRED, "", "", just_now_ms);
284 }
285 
286 //
287 // Update the Bluetooth release wakelock statistics.
288 //
289 // This function should be called every time when the wakelock is released.
290 // |released_status| is the status code that was return when the wakelock was
291 // released.
292 // This function is thread-safe.
293 //
update_wakelock_released_stats(bt_status_t released_status)294 static void update_wakelock_released_stats(bt_status_t released_status) {
295   const uint64_t just_now_ms = now_ms();
296 
297   std::lock_guard<std::mutex> lock(stats_mutex);
298 
299   if (released_status != BT_STATUS_SUCCESS) {
300     wakelock_stats.released_errors++;
301     wakelock_stats.last_released_error = released_status;
302   }
303 
304   if (!wakelock_stats.is_acquired) {
305     return;
306   }
307 
308   wakelock_stats.is_acquired = false;
309   wakelock_stats.released_count++;
310   wakelock_stats.last_released_timestamp_ms = just_now_ms;
311 
312   // Compute the acquired interval and update the statistics
313   uint64_t delta_ms = just_now_ms - wakelock_stats.last_acquired_timestamp_ms;
314   if (delta_ms < wakelock_stats.min_acquired_interval_ms ||
315       wakelock_stats.released_count == 1) {
316     wakelock_stats.min_acquired_interval_ms = delta_ms;
317   }
318   if (delta_ms > wakelock_stats.max_acquired_interval_ms) {
319     wakelock_stats.max_acquired_interval_ms = delta_ms;
320   }
321   wakelock_stats.last_acquired_interval_ms = delta_ms;
322   wakelock_stats.total_acquired_interval_ms += delta_ms;
323 
324   BluetoothMetricsLogger::GetInstance()->LogWakeEvent(
325       bluetooth::common::WAKE_EVENT_RELEASED, "", "", just_now_ms);
326 }
327 
wakelock_debug_dump(int fd)328 void wakelock_debug_dump(int fd) {
329   const uint64_t just_now_ms = now_ms();
330 
331   std::lock_guard<std::mutex> lock(stats_mutex);
332 
333   // Compute the last acquired interval if the wakelock is still acquired
334   uint64_t delta_ms = 0;
335   uint64_t last_interval_ms = wakelock_stats.last_acquired_interval_ms;
336   uint64_t min_interval_ms = wakelock_stats.min_acquired_interval_ms;
337   uint64_t max_interval_ms = wakelock_stats.max_acquired_interval_ms;
338   uint64_t avg_interval_ms = 0;
339 
340   if (wakelock_stats.is_acquired) {
341     delta_ms = just_now_ms - wakelock_stats.last_acquired_timestamp_ms;
342     if (delta_ms > max_interval_ms) max_interval_ms = delta_ms;
343     if (delta_ms < min_interval_ms) min_interval_ms = delta_ms;
344     last_interval_ms = delta_ms;
345   }
346   uint64_t total_interval_ms =
347       wakelock_stats.total_acquired_interval_ms + delta_ms;
348 
349   if (wakelock_stats.acquired_count > 0)
350     avg_interval_ms = total_interval_ms / wakelock_stats.acquired_count;
351 
352   dprintf(fd, "\nBluetooth Wakelock Statistics:\n");
353   dprintf(fd, "  Is acquired                    : %s\n",
354           wakelock_stats.is_acquired ? "true" : "false");
355   dprintf(fd, "  Acquired/released count        : %zu / %zu\n",
356           wakelock_stats.acquired_count, wakelock_stats.released_count);
357   dprintf(fd, "  Acquired/released error count  : %zu / %zu\n",
358           wakelock_stats.acquired_errors, wakelock_stats.released_errors);
359   dprintf(fd, "  Last acquire/release error code: %d / %d\n",
360           wakelock_stats.last_acquired_error,
361           wakelock_stats.last_released_error);
362   dprintf(fd, "  Last acquired time (ms)        : %llu\n",
363           (unsigned long long)last_interval_ms);
364   dprintf(fd, "  Acquired time min/max/avg (ms) : %llu / %llu / %llu\n",
365           (unsigned long long)min_interval_ms,
366           (unsigned long long)max_interval_ms,
367           (unsigned long long)avg_interval_ms);
368   dprintf(fd, "  Total acquired time (ms)       : %llu\n",
369           (unsigned long long)total_interval_ms);
370   dprintf(fd, "  Total run time (ms)            : %llu\n",
371           (unsigned long long)(just_now_ms -
372                                wakelock_stats.last_reset_timestamp_ms));
373 }
374