alarm.cc revision a8215323a1e6f21c8442943f68f8fbe59a3f9ba6
1/****************************************************************************** 2 * 3 * Copyright (C) 2014 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#include "include/bt_target.h" 20 21#define LOG_TAG "bt_osi_alarm" 22 23#include "osi/include/alarm.h" 24 25#include <base/logging.h> 26#include <errno.h> 27#include <fcntl.h> 28#include <inttypes.h> 29#include <malloc.h> 30#include <signal.h> 31#include <string.h> 32#include <time.h> 33 34#include <hardware/bluetooth.h> 35 36#include <mutex> 37 38#include "osi/include/allocator.h" 39#include "osi/include/fixed_queue.h" 40#include "osi/include/list.h" 41#include "osi/include/log.h" 42#include "osi/include/osi.h" 43#include "osi/include/semaphore.h" 44#include "osi/include/thread.h" 45#include "osi/include/wakelock.h" 46 47// Make callbacks run at high thread priority. Some callbacks are used for audio 48// related timer tasks as well as re-transmissions etc. Since we at this point 49// cannot differentiate what callback we are dealing with, assume high priority 50// for now. 51// TODO(eisenbach): Determine correct thread priority (from parent?/per alarm?) 52static const int CALLBACK_THREAD_PRIORITY_HIGH = -19; 53 54typedef struct { 55 size_t count; 56 period_ms_t total_ms; 57 period_ms_t max_ms; 58} stat_t; 59 60// Alarm-related information and statistics 61typedef struct { 62 const char* name; 63 size_t scheduled_count; 64 size_t canceled_count; 65 size_t rescheduled_count; 66 size_t total_updates; 67 period_ms_t last_update_ms; 68 stat_t callback_execution; 69 stat_t overdue_scheduling; 70 stat_t premature_scheduling; 71} alarm_stats_t; 72 73struct alarm_t { 74 // The mutex is held while the callback for this alarm is being executed. 75 // It allows us to release the coarse-grained monitor lock while a 76 // potentially long-running callback is executing. |alarm_cancel| uses this 77 // mutex to provide a guarantee to its caller that the callback will not be 78 // in progress when it returns. 79 std::recursive_mutex* callback_mutex; 80 period_ms_t creation_time; 81 period_ms_t period; 82 period_ms_t deadline; 83 period_ms_t prev_deadline; // Previous deadline - used for accounting of 84 // periodic timers 85 bool is_periodic; 86 fixed_queue_t* queue; // The processing queue to add this alarm to 87 alarm_callback_t callback; 88 void* data; 89 alarm_stats_t stats; 90}; 91 92// If the next wakeup time is less than this threshold, we should acquire 93// a wakelock instead of setting a wake alarm so we're not bouncing in 94// and out of suspend frequently. This value is externally visible to allow 95// unit tests to run faster. It should not be modified by production code. 96int64_t TIMER_INTERVAL_FOR_WAKELOCK_IN_MS = 3000; 97static const clockid_t CLOCK_ID = CLOCK_BOOTTIME; 98 99#if (KERNEL_MISSING_CLOCK_BOOTTIME_ALARM == TRUE) 100static const clockid_t CLOCK_ID_ALARM = CLOCK_BOOTTIME; 101#else 102static const clockid_t CLOCK_ID_ALARM = CLOCK_BOOTTIME_ALARM; 103#endif 104 105// This mutex ensures that the |alarm_set|, |alarm_cancel|, and alarm callback 106// functions execute serially and not concurrently. As a result, this mutex 107// also protects the |alarms| list. 108static std::mutex alarms_mutex; 109static list_t* alarms; 110static timer_t timer; 111static timer_t wakeup_timer; 112static bool timer_set; 113 114// All alarm callbacks are dispatched from |dispatcher_thread| 115static thread_t* dispatcher_thread; 116static bool dispatcher_thread_active; 117static semaphore_t* alarm_expired; 118 119// Default alarm callback thread and queue 120static thread_t* default_callback_thread; 121static fixed_queue_t* default_callback_queue; 122 123static alarm_t* alarm_new_internal(const char* name, bool is_periodic); 124static bool lazy_initialize(void); 125static period_ms_t now(void); 126static void alarm_set_internal(alarm_t* alarm, period_ms_t period, 127 alarm_callback_t cb, void* data, 128 fixed_queue_t* queue); 129static void alarm_cancel_internal(alarm_t* alarm); 130static void remove_pending_alarm(alarm_t* alarm); 131static void schedule_next_instance(alarm_t* alarm); 132static void reschedule_root_alarm(void); 133static void alarm_queue_ready(fixed_queue_t* queue, void* context); 134static void timer_callback(void* data); 135static void callback_dispatch(void* context); 136static bool timer_create_internal(const clockid_t clock_id, timer_t* timer); 137static void update_scheduling_stats(alarm_stats_t* stats, period_ms_t now_ms, 138 period_ms_t deadline_ms, 139 period_ms_t execution_delta_ms); 140 141static void update_stat(stat_t* stat, period_ms_t delta) { 142 if (stat->max_ms < delta) stat->max_ms = delta; 143 stat->total_ms += delta; 144 stat->count++; 145} 146 147alarm_t* alarm_new(const char* name) { return alarm_new_internal(name, false); } 148 149alarm_t* alarm_new_periodic(const char* name) { 150 return alarm_new_internal(name, true); 151} 152 153static alarm_t* alarm_new_internal(const char* name, bool is_periodic) { 154 // Make sure we have a list we can insert alarms into. 155 if (!alarms && !lazy_initialize()) { 156 CHECK(false); // if initialization failed, we should not continue 157 return NULL; 158 } 159 160 alarm_t* ret = static_cast<alarm_t*>(osi_calloc(sizeof(alarm_t))); 161 162 ret->callback_mutex = new std::recursive_mutex; 163 ret->is_periodic = is_periodic; 164 ret->stats.name = osi_strdup(name); 165 // NOTE: The stats were reset by osi_calloc() above 166 167 return ret; 168} 169 170void alarm_free(alarm_t* alarm) { 171 if (!alarm) return; 172 173 alarm_cancel(alarm); 174 delete alarm->callback_mutex; 175 osi_free((void*)alarm->stats.name); 176 osi_free(alarm); 177} 178 179period_ms_t alarm_get_remaining_ms(const alarm_t* alarm) { 180 CHECK(alarm != NULL); 181 period_ms_t remaining_ms = 0; 182 period_ms_t just_now = now(); 183 184 std::lock_guard<std::mutex> lock(alarms_mutex); 185 if (alarm->deadline > just_now) remaining_ms = alarm->deadline - just_now; 186 187 return remaining_ms; 188} 189 190void alarm_set(alarm_t* alarm, period_ms_t interval_ms, alarm_callback_t cb, 191 void* data) { 192 alarm_set_on_queue(alarm, interval_ms, cb, data, default_callback_queue); 193} 194 195void alarm_set_on_queue(alarm_t* alarm, period_ms_t interval_ms, 196 alarm_callback_t cb, void* data, fixed_queue_t* queue) { 197 CHECK(queue != NULL); 198 alarm_set_internal(alarm, interval_ms, cb, data, queue); 199} 200 201// Runs in exclusion with alarm_cancel and timer_callback. 202static void alarm_set_internal(alarm_t* alarm, period_ms_t period, 203 alarm_callback_t cb, void* data, 204 fixed_queue_t* queue) { 205 CHECK(alarms != NULL); 206 CHECK(alarm != NULL); 207 CHECK(cb != NULL); 208 209 std::lock_guard<std::mutex> lock(alarms_mutex); 210 211 alarm->creation_time = now(); 212 alarm->period = period; 213 alarm->queue = queue; 214 alarm->callback = cb; 215 alarm->data = data; 216 217 schedule_next_instance(alarm); 218 alarm->stats.scheduled_count++; 219} 220 221void alarm_cancel(alarm_t* alarm) { 222 CHECK(alarms != NULL); 223 if (!alarm) return; 224 225 { 226 std::lock_guard<std::mutex> lock(alarms_mutex); 227 alarm_cancel_internal(alarm); 228 } 229 230 // If the callback for |alarm| is in progress, wait here until it completes. 231 std::lock_guard<std::recursive_mutex> lock(*alarm->callback_mutex); 232} 233 234// Internal implementation of canceling an alarm. 235// The caller must hold the |alarms_mutex| 236static void alarm_cancel_internal(alarm_t* alarm) { 237 bool needs_reschedule = 238 (!list_is_empty(alarms) && list_front(alarms) == alarm); 239 240 remove_pending_alarm(alarm); 241 242 alarm->deadline = 0; 243 alarm->prev_deadline = 0; 244 alarm->callback = NULL; 245 alarm->data = NULL; 246 alarm->stats.canceled_count++; 247 alarm->queue = NULL; 248 249 if (needs_reschedule) reschedule_root_alarm(); 250} 251 252bool alarm_is_scheduled(const alarm_t* alarm) { 253 if ((alarms == NULL) || (alarm == NULL)) return false; 254 return (alarm->callback != NULL); 255} 256 257void alarm_cleanup(void) { 258 // If lazy_initialize never ran there is nothing else to do 259 if (!alarms) return; 260 261 dispatcher_thread_active = false; 262 semaphore_post(alarm_expired); 263 thread_free(dispatcher_thread); 264 dispatcher_thread = NULL; 265 266 std::lock_guard<std::mutex> lock(alarms_mutex); 267 268 fixed_queue_free(default_callback_queue, NULL); 269 default_callback_queue = NULL; 270 thread_free(default_callback_thread); 271 default_callback_thread = NULL; 272 273 timer_delete(wakeup_timer); 274 timer_delete(timer); 275 semaphore_free(alarm_expired); 276 alarm_expired = NULL; 277 278 list_free(alarms); 279 alarms = NULL; 280} 281 282static bool lazy_initialize(void) { 283 CHECK(alarms == NULL); 284 285 // timer_t doesn't have an invalid value so we must track whether 286 // the |timer| variable is valid ourselves. 287 bool timer_initialized = false; 288 bool wakeup_timer_initialized = false; 289 290 std::lock_guard<std::mutex> lock(alarms_mutex); 291 292 alarms = list_new(NULL); 293 if (!alarms) { 294 LOG_ERROR(LOG_TAG, "%s unable to allocate alarm list.", __func__); 295 goto error; 296 } 297 298 if (!timer_create_internal(CLOCK_ID, &timer)) goto error; 299 timer_initialized = true; 300 301 if (!timer_create_internal(CLOCK_ID_ALARM, &wakeup_timer)) goto error; 302 wakeup_timer_initialized = true; 303 304 alarm_expired = semaphore_new(0); 305 if (!alarm_expired) { 306 LOG_ERROR(LOG_TAG, "%s unable to create alarm expired semaphore", __func__); 307 goto error; 308 } 309 310 default_callback_thread = 311 thread_new_sized("alarm_default_callbacks", SIZE_MAX); 312 if (default_callback_thread == NULL) { 313 LOG_ERROR(LOG_TAG, "%s unable to create default alarm callbacks thread.", 314 __func__); 315 goto error; 316 } 317 thread_set_priority(default_callback_thread, CALLBACK_THREAD_PRIORITY_HIGH); 318 default_callback_queue = fixed_queue_new(SIZE_MAX); 319 if (default_callback_queue == NULL) { 320 LOG_ERROR(LOG_TAG, "%s unable to create default alarm callbacks queue.", 321 __func__); 322 goto error; 323 } 324 alarm_register_processing_queue(default_callback_queue, 325 default_callback_thread); 326 327 dispatcher_thread_active = true; 328 dispatcher_thread = thread_new("alarm_dispatcher"); 329 if (!dispatcher_thread) { 330 LOG_ERROR(LOG_TAG, "%s unable to create alarm callback thread.", __func__); 331 goto error; 332 } 333 334 thread_set_priority(dispatcher_thread, CALLBACK_THREAD_PRIORITY_HIGH); 335 thread_post(dispatcher_thread, callback_dispatch, NULL); 336 return true; 337 338error: 339 fixed_queue_free(default_callback_queue, NULL); 340 default_callback_queue = NULL; 341 thread_free(default_callback_thread); 342 default_callback_thread = NULL; 343 344 thread_free(dispatcher_thread); 345 dispatcher_thread = NULL; 346 347 dispatcher_thread_active = false; 348 349 semaphore_free(alarm_expired); 350 alarm_expired = NULL; 351 352 if (wakeup_timer_initialized) timer_delete(wakeup_timer); 353 354 if (timer_initialized) timer_delete(timer); 355 356 list_free(alarms); 357 alarms = NULL; 358 359 return false; 360} 361 362static period_ms_t now(void) { 363 CHECK(alarms != NULL); 364 365 struct timespec ts; 366 if (clock_gettime(CLOCK_ID, &ts) == -1) { 367 LOG_ERROR(LOG_TAG, "%s unable to get current time: %s", __func__, 368 strerror(errno)); 369 return 0; 370 } 371 372 return (ts.tv_sec * 1000LL) + (ts.tv_nsec / 1000000LL); 373} 374 375// Remove alarm from internal alarm list and the processing queue 376// The caller must hold the |alarms_mutex| 377static void remove_pending_alarm(alarm_t* alarm) { 378 list_remove(alarms, alarm); 379 while (fixed_queue_try_remove_from_queue(alarm->queue, alarm) != NULL) { 380 // Remove all repeated alarm instances from the queue. 381 // NOTE: We are defensive here - we shouldn't have repeated alarm instances 382 } 383} 384 385// Must be called with |alarms_mutex| held 386static void schedule_next_instance(alarm_t* alarm) { 387 // If the alarm is currently set and it's at the start of the list, 388 // we'll need to re-schedule since we've adjusted the earliest deadline. 389 bool needs_reschedule = 390 (!list_is_empty(alarms) && list_front(alarms) == alarm); 391 if (alarm->callback) remove_pending_alarm(alarm); 392 393 // Calculate the next deadline for this alarm 394 period_ms_t just_now = now(); 395 period_ms_t ms_into_period = 0; 396 if ((alarm->is_periodic) && (alarm->period != 0)) 397 ms_into_period = ((just_now - alarm->creation_time) % alarm->period); 398 alarm->deadline = just_now + (alarm->period - ms_into_period); 399 400 // Add it into the timer list sorted by deadline (earliest deadline first). 401 if (list_is_empty(alarms) || 402 ((alarm_t*)list_front(alarms))->deadline > alarm->deadline) { 403 list_prepend(alarms, alarm); 404 } else { 405 for (list_node_t* node = list_begin(alarms); node != list_end(alarms); 406 node = list_next(node)) { 407 list_node_t* next = list_next(node); 408 if (next == list_end(alarms) || 409 ((alarm_t*)list_node(next))->deadline > alarm->deadline) { 410 list_insert_after(alarms, node, alarm); 411 break; 412 } 413 } 414 } 415 416 // If the new alarm has the earliest deadline, we need to re-evaluate our 417 // schedule. 418 if (needs_reschedule || 419 (!list_is_empty(alarms) && list_front(alarms) == alarm)) { 420 reschedule_root_alarm(); 421 } 422} 423 424// NOTE: must be called with |alarms_mutex| held 425static void reschedule_root_alarm(void) { 426 CHECK(alarms != NULL); 427 428 const bool timer_was_set = timer_set; 429 alarm_t* next; 430 int64_t next_expiration; 431 432 // If used in a zeroed state, disarms the timer. 433 struct itimerspec timer_time; 434 memset(&timer_time, 0, sizeof(timer_time)); 435 436 if (list_is_empty(alarms)) goto done; 437 438 next = static_cast<alarm_t*>(list_front(alarms)); 439 next_expiration = next->deadline - now(); 440 if (next_expiration < TIMER_INTERVAL_FOR_WAKELOCK_IN_MS) { 441 if (!timer_set) { 442 if (!wakelock_acquire()) { 443 LOG_ERROR(LOG_TAG, "%s unable to acquire wake lock", __func__); 444 goto done; 445 } 446 } 447 448 timer_time.it_value.tv_sec = (next->deadline / 1000); 449 timer_time.it_value.tv_nsec = (next->deadline % 1000) * 1000000LL; 450 451 // It is entirely unsafe to call timer_settime(2) with a zeroed timerspec 452 // for timers with *_ALARM clock IDs. Although the man page states that the 453 // timer would be canceled, the current behavior (as of Linux kernel 3.17) 454 // is that the callback is issued immediately. The only way to cancel an 455 // *_ALARM timer is to delete the timer. But unfortunately, deleting and 456 // re-creating a timer is rather expensive; every timer_create(2) spawns a 457 // new thread. So we simply set the timer to fire at the largest possible 458 // time. 459 // 460 // If we've reached this code path, we're going to grab a wake lock and 461 // wait for the next timer to fire. In that case, there's no reason to 462 // have a pending wakeup timer so we simply cancel it. 463 struct itimerspec end_of_time; 464 memset(&end_of_time, 0, sizeof(end_of_time)); 465 end_of_time.it_value.tv_sec = (time_t)(1LL << (sizeof(time_t) * 8 - 2)); 466 timer_settime(wakeup_timer, TIMER_ABSTIME, &end_of_time, NULL); 467 } else { 468 // WARNING: do not attempt to use relative timers with *_ALARM clock IDs 469 // in kernels before 3.17 unless you have the following patch: 470 // https://lkml.org/lkml/2014/7/7/576 471 struct itimerspec wakeup_time; 472 memset(&wakeup_time, 0, sizeof(wakeup_time)); 473 474 wakeup_time.it_value.tv_sec = (next->deadline / 1000); 475 wakeup_time.it_value.tv_nsec = (next->deadline % 1000) * 1000000LL; 476 if (timer_settime(wakeup_timer, TIMER_ABSTIME, &wakeup_time, NULL) == -1) 477 LOG_ERROR(LOG_TAG, "%s unable to set wakeup timer: %s", __func__, 478 strerror(errno)); 479 } 480 481done: 482 timer_set = 483 timer_time.it_value.tv_sec != 0 || timer_time.it_value.tv_nsec != 0; 484 if (timer_was_set && !timer_set) { 485 wakelock_release(); 486 } 487 488 if (timer_settime(timer, TIMER_ABSTIME, &timer_time, NULL) == -1) 489 LOG_ERROR(LOG_TAG, "%s unable to set timer: %s", __func__, strerror(errno)); 490 491 // If next expiration was in the past (e.g. short timer that got context 492 // switched) then the timer might have diarmed itself. Detect this case and 493 // work around it by manually signalling the |alarm_expired| semaphore. 494 // 495 // It is possible that the timer was actually super short (a few 496 // milliseconds) and the timer expired normally before we called 497 // |timer_gettime|. Worst case, |alarm_expired| is signaled twice for that 498 // alarm. Nothing bad should happen in that case though since the callback 499 // dispatch function checks to make sure the timer at the head of the list 500 // actually expired. 501 if (timer_set) { 502 struct itimerspec time_to_expire; 503 timer_gettime(timer, &time_to_expire); 504 if (time_to_expire.it_value.tv_sec == 0 && 505 time_to_expire.it_value.tv_nsec == 0) { 506 LOG_DEBUG( 507 LOG_TAG, 508 "%s alarm expiration too close for posix timers, switching to guns", 509 __func__); 510 semaphore_post(alarm_expired); 511 } 512 } 513} 514 515void alarm_register_processing_queue(fixed_queue_t* queue, thread_t* thread) { 516 CHECK(queue != NULL); 517 CHECK(thread != NULL); 518 519 fixed_queue_register_dequeue(queue, thread_get_reactor(thread), 520 alarm_queue_ready, NULL); 521} 522 523void alarm_unregister_processing_queue(fixed_queue_t* queue) { 524 CHECK(alarms != NULL); 525 CHECK(queue != NULL); 526 527 fixed_queue_unregister_dequeue(queue); 528 529 // Cancel all alarms that are using this queue 530 std::lock_guard<std::mutex> lock(alarms_mutex); 531 for (list_node_t* node = list_begin(alarms); node != list_end(alarms);) { 532 alarm_t* alarm = (alarm_t*)list_node(node); 533 node = list_next(node); 534 // TODO: Each module is responsible for tearing down its alarms; currently, 535 // this is not the case. In the future, this check should be replaced by 536 // an assert. 537 if (alarm->queue == queue) alarm_cancel_internal(alarm); 538 } 539} 540 541static void alarm_queue_ready(fixed_queue_t* queue, UNUSED_ATTR void* context) { 542 CHECK(queue != NULL); 543 544 std::unique_lock<std::mutex> lock(alarms_mutex); 545 alarm_t* alarm = (alarm_t*)fixed_queue_try_dequeue(queue); 546 if (alarm == NULL) { 547 return; // The alarm was probably canceled 548 } 549 550 // 551 // If the alarm is not periodic, we've fully serviced it now, and can reset 552 // some of its internal state. This is useful to distinguish between expired 553 // alarms and active ones. 554 // 555 alarm_callback_t callback = alarm->callback; 556 void* data = alarm->data; 557 period_ms_t deadline = alarm->deadline; 558 if (alarm->is_periodic) { 559 // The periodic alarm has been rescheduled and alarm->deadline has been 560 // updated, hence we need to use the previous deadline. 561 deadline = alarm->prev_deadline; 562 } else { 563 alarm->deadline = 0; 564 alarm->callback = NULL; 565 alarm->data = NULL; 566 alarm->queue = NULL; 567 } 568 569 std::lock_guard<std::recursive_mutex> cb_lock(*alarm->callback_mutex); 570 lock.unlock(); 571 572 period_ms_t t0 = now(); 573 callback(data); 574 period_ms_t t1 = now(); 575 576 // Update the statistics 577 CHECK(t1 >= t0); 578 period_ms_t delta = t1 - t0; 579 update_scheduling_stats(&alarm->stats, t0, deadline, delta); 580} 581 582// Callback function for wake alarms and our posix timer 583static void timer_callback(UNUSED_ATTR void* ptr) { 584 semaphore_post(alarm_expired); 585} 586 587// Function running on |dispatcher_thread| that performs the following: 588// (1) Receives a signal using |alarm_exired| that the alarm has expired 589// (2) Dispatches the alarm callback for processing by the corresponding 590// thread for that alarm. 591static void callback_dispatch(UNUSED_ATTR void* context) { 592 while (true) { 593 semaphore_wait(alarm_expired); 594 if (!dispatcher_thread_active) break; 595 596 std::lock_guard<std::mutex> lock(alarms_mutex); 597 alarm_t* alarm; 598 599 // Take into account that the alarm may get cancelled before we get to it. 600 // We're done here if there are no alarms or the alarm at the front is in 601 // the future. Exit right away since there's nothing left to do. 602 if (list_is_empty(alarms) || 603 (alarm = static_cast<alarm_t*>(list_front(alarms)))->deadline > now()) { 604 reschedule_root_alarm(); 605 continue; 606 } 607 608 list_remove(alarms, alarm); 609 610 if (alarm->is_periodic) { 611 alarm->prev_deadline = alarm->deadline; 612 schedule_next_instance(alarm); 613 alarm->stats.rescheduled_count++; 614 } 615 reschedule_root_alarm(); 616 617 // Enqueue the alarm for processing 618 fixed_queue_enqueue(alarm->queue, alarm); 619 } 620 621 LOG_DEBUG(LOG_TAG, "%s Callback thread exited", __func__); 622} 623 624static bool timer_create_internal(const clockid_t clock_id, timer_t* timer) { 625 CHECK(timer != NULL); 626 627 struct sigevent sigevent; 628 memset(&sigevent, 0, sizeof(sigevent)); 629 sigevent.sigev_notify = SIGEV_THREAD; 630 sigevent.sigev_notify_function = (void (*)(union sigval))timer_callback; 631 if (timer_create(clock_id, &sigevent, timer) == -1) { 632 LOG_ERROR(LOG_TAG, "%s unable to create timer with clock %d: %s", __func__, 633 clock_id, strerror(errno)); 634 if (clock_id == CLOCK_BOOTTIME_ALARM) { 635 LOG_ERROR(LOG_TAG, 636 "The kernel might not have support for " 637 "timer_create(CLOCK_BOOTTIME_ALARM): " 638 "https://lwn.net/Articles/429925/"); 639 LOG_ERROR(LOG_TAG, 640 "See following patches: " 641 "https://git.kernel.org/cgit/linux/kernel/git/torvalds/" 642 "linux.git/log/?qt=grep&q=CLOCK_BOOTTIME_ALARM"); 643 } 644 return false; 645 } 646 647 return true; 648} 649 650static void update_scheduling_stats(alarm_stats_t* stats, period_ms_t now_ms, 651 period_ms_t deadline_ms, 652 period_ms_t execution_delta_ms) { 653 stats->total_updates++; 654 stats->last_update_ms = now_ms; 655 656 update_stat(&stats->callback_execution, execution_delta_ms); 657 658 if (deadline_ms < now_ms) { 659 // Overdue scheduling 660 period_ms_t delta_ms = now_ms - deadline_ms; 661 update_stat(&stats->overdue_scheduling, delta_ms); 662 } else if (deadline_ms > now_ms) { 663 // Premature scheduling 664 period_ms_t delta_ms = deadline_ms - now_ms; 665 update_stat(&stats->premature_scheduling, delta_ms); 666 } 667} 668 669static void dump_stat(int fd, stat_t* stat, const char* description) { 670 period_ms_t average_time_ms = 0; 671 if (stat->count != 0) average_time_ms = stat->total_ms / stat->count; 672 673 dprintf(fd, "%-51s: %llu / %llu / %llu\n", description, 674 (unsigned long long)stat->total_ms, (unsigned long long)stat->max_ms, 675 (unsigned long long)average_time_ms); 676} 677 678void alarm_debug_dump(int fd) { 679 dprintf(fd, "\nBluetooth Alarms Statistics:\n"); 680 681 std::lock_guard<std::mutex> lock(alarms_mutex); 682 683 if (alarms == NULL) { 684 dprintf(fd, " None\n"); 685 return; 686 } 687 688 period_ms_t just_now = now(); 689 690 dprintf(fd, " Total Alarms: %zu\n\n", list_length(alarms)); 691 692 // Dump info for each alarm 693 for (list_node_t* node = list_begin(alarms); node != list_end(alarms); 694 node = list_next(node)) { 695 alarm_t* alarm = (alarm_t*)list_node(node); 696 alarm_stats_t* stats = &alarm->stats; 697 698 dprintf(fd, " Alarm : %s (%s)\n", stats->name, 699 (alarm->is_periodic) ? "PERIODIC" : "SINGLE"); 700 701 dprintf(fd, "%-51s: %zu / %zu / %zu / %zu\n", 702 " Action counts (sched/resched/exec/cancel)", 703 stats->scheduled_count, stats->rescheduled_count, 704 stats->callback_execution.count, stats->canceled_count); 705 706 dprintf(fd, "%-51s: %zu / %zu\n", 707 " Deviation counts (overdue/premature)", 708 stats->overdue_scheduling.count, stats->premature_scheduling.count); 709 710 dprintf(fd, "%-51s: %llu / %llu / %lld\n", 711 " Time in ms (since creation/interval/remaining)", 712 (unsigned long long)(just_now - alarm->creation_time), 713 (unsigned long long)alarm->period, 714 (long long)(alarm->deadline - just_now)); 715 716 dump_stat(fd, &stats->callback_execution, 717 " Callback execution time in ms (total/max/avg)"); 718 719 dump_stat(fd, &stats->overdue_scheduling, 720 " Overdue scheduling time in ms (total/max/avg)"); 721 722 dump_stat(fd, &stats->premature_scheduling, 723 " Premature scheduling time in ms (total/max/avg)"); 724 725 dprintf(fd, "\n"); 726 } 727} 728