/****************************************************************************** * * Copyright 2014 Google, Inc. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at: * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. * ******************************************************************************/ #include "internal_include/bt_target.h" #define LOG_TAG "bt_osi_alarm" #include "osi/include/alarm.h" #include #include #include #include #include #include #include #include #include #include #include #include #include "osi/include/allocator.h" #include "osi/include/fixed_queue.h" #include "osi/include/list.h" #include "osi/include/log.h" #include "osi/include/osi.h" #include "osi/include/semaphore.h" #include "osi/include/thread.h" #include "osi/include/wakelock.h" #include "stack/include/btu.h" using base::Bind; using base::CancelableClosure; // Callback and timer threads should run at RT priority in order to ensure they // meet audio deadlines. Use this priority for all audio/timer related thread. static const int THREAD_RT_PRIORITY = 1; typedef struct { size_t count; uint64_t total_ms; uint64_t max_ms; } stat_t; // Alarm-related information and statistics typedef struct { const char* name; size_t scheduled_count; size_t canceled_count; size_t rescheduled_count; size_t total_updates; uint64_t last_update_ms; stat_t overdue_scheduling; stat_t premature_scheduling; } alarm_stats_t; /* Wrapper around CancellableClosure that let it be embedded in structs, without * need to define copy operator. */ struct CancelableClosureInStruct { base::CancelableClosure i; CancelableClosureInStruct& operator=(const CancelableClosureInStruct& in) { if (!in.i.callback().is_null()) i.Reset(in.i.callback()); return *this; } }; struct alarm_t { // The mutex is held while the callback for this alarm is being executed. // It allows us to release the coarse-grained monitor lock while a // potentially long-running callback is executing. |alarm_cancel| uses this // mutex to provide a guarantee to its caller that the callback will not be // in progress when it returns. std::shared_ptr callback_mutex; uint64_t creation_time_ms; uint64_t period_ms; uint64_t deadline_ms; uint64_t prev_deadline_ms; // Previous deadline - used for accounting of // periodic timers bool is_periodic; fixed_queue_t* queue; // The processing queue to add this alarm to alarm_callback_t callback; void* data; alarm_stats_t stats; bool for_msg_loop; // True, if the alarm should be processed on message loop CancelableClosureInStruct closure; // posted to message loop for processing }; // If the next wakeup time is less than this threshold, we should acquire // a wakelock instead of setting a wake alarm so we're not bouncing in // and out of suspend frequently. This value is externally visible to allow // unit tests to run faster. It should not be modified by production code. int64_t TIMER_INTERVAL_FOR_WAKELOCK_IN_MS = 3000; static const clockid_t CLOCK_ID = CLOCK_BOOTTIME; // This mutex ensures that the |alarm_set|, |alarm_cancel|, and alarm callback // functions execute serially and not concurrently. As a result, this mutex // also protects the |alarms| list. static std::mutex alarms_mutex; static list_t* alarms; static timer_t timer; static timer_t wakeup_timer; static bool timer_set; // All alarm callbacks are dispatched from |dispatcher_thread| static thread_t* dispatcher_thread; static bool dispatcher_thread_active; static semaphore_t* alarm_expired; // Default alarm callback thread and queue static thread_t* default_callback_thread; static fixed_queue_t* default_callback_queue; static alarm_t* alarm_new_internal(const char* name, bool is_periodic); static bool lazy_initialize(void); static uint64_t now_ms(void); static void alarm_set_internal(alarm_t* alarm, uint64_t period_ms, alarm_callback_t cb, void* data, fixed_queue_t* queue, bool for_msg_loop); static void alarm_cancel_internal(alarm_t* alarm); static void remove_pending_alarm(alarm_t* alarm); static void schedule_next_instance(alarm_t* alarm); static void reschedule_root_alarm(void); static void alarm_queue_ready(fixed_queue_t* queue, void* context); static void timer_callback(void* data); static void callback_dispatch(void* context); static bool timer_create_internal(const clockid_t clock_id, timer_t* timer); static void update_scheduling_stats(alarm_stats_t* stats, uint64_t now_ms, uint64_t deadline_ms); // Registers |queue| for processing alarm callbacks on |thread|. // |queue| may not be NULL. |thread| may not be NULL. static void alarm_register_processing_queue(fixed_queue_t* queue, thread_t* thread); static void update_stat(stat_t* stat, uint64_t delta_ms) { if (stat->max_ms < delta_ms) stat->max_ms = delta_ms; stat->total_ms += delta_ms; stat->count++; } alarm_t* alarm_new(const char* name) { return alarm_new_internal(name, false); } alarm_t* alarm_new_periodic(const char* name) { return alarm_new_internal(name, true); } static alarm_t* alarm_new_internal(const char* name, bool is_periodic) { // Make sure we have a list we can insert alarms into. if (!alarms && !lazy_initialize()) { CHECK(false); // if initialization failed, we should not continue return NULL; } alarm_t* ret = static_cast(osi_calloc(sizeof(alarm_t))); std::shared_ptr ptr(new std::recursive_mutex()); ret->callback_mutex = ptr; ret->is_periodic = is_periodic; ret->stats.name = osi_strdup(name); ret->for_msg_loop = false; // placement new new (&ret->closure) CancelableClosureInStruct(); // NOTE: The stats were reset by osi_calloc() above return ret; } void alarm_free(alarm_t* alarm) { if (!alarm) return; alarm_cancel(alarm); osi_free((void*)alarm->stats.name); alarm->closure.~CancelableClosureInStruct(); alarm->callback_mutex.reset(); osi_free(alarm); } uint64_t alarm_get_remaining_ms(const alarm_t* alarm) { CHECK(alarm != NULL); uint64_t remaining_ms = 0; uint64_t just_now_ms = now_ms(); std::lock_guard lock(alarms_mutex); if (alarm->deadline_ms > just_now_ms) remaining_ms = alarm->deadline_ms - just_now_ms; return remaining_ms; } void alarm_set(alarm_t* alarm, uint64_t interval_ms, alarm_callback_t cb, void* data) { alarm_set_internal(alarm, interval_ms, cb, data, default_callback_queue, false); } void alarm_set_on_mloop(alarm_t* alarm, uint64_t interval_ms, alarm_callback_t cb, void* data) { alarm_set_internal(alarm, interval_ms, cb, data, NULL, true); } // Runs in exclusion with alarm_cancel and timer_callback. static void alarm_set_internal(alarm_t* alarm, uint64_t period_ms, alarm_callback_t cb, void* data, fixed_queue_t* queue, bool for_msg_loop) { CHECK(alarms != NULL); CHECK(alarm != NULL); CHECK(cb != NULL); std::lock_guard lock(alarms_mutex); alarm->creation_time_ms = now_ms(); alarm->period_ms = period_ms; alarm->queue = queue; alarm->callback = cb; alarm->data = data; alarm->for_msg_loop = for_msg_loop; schedule_next_instance(alarm); alarm->stats.scheduled_count++; } void alarm_cancel(alarm_t* alarm) { CHECK(alarms != NULL); if (!alarm) return; std::shared_ptr local_mutex_ref; { std::lock_guard lock(alarms_mutex); local_mutex_ref = alarm->callback_mutex; alarm_cancel_internal(alarm); } // If the callback for |alarm| is in progress, wait here until it completes. std::lock_guard lock(*local_mutex_ref); } // Internal implementation of canceling an alarm. // The caller must hold the |alarms_mutex| static void alarm_cancel_internal(alarm_t* alarm) { bool needs_reschedule = (!list_is_empty(alarms) && list_front(alarms) == alarm); remove_pending_alarm(alarm); alarm->deadline_ms = 0; alarm->prev_deadline_ms = 0; alarm->callback = NULL; alarm->data = NULL; alarm->stats.canceled_count++; alarm->queue = NULL; if (needs_reschedule) reschedule_root_alarm(); } bool alarm_is_scheduled(const alarm_t* alarm) { if ((alarms == NULL) || (alarm == NULL)) return false; return (alarm->callback != NULL); } void alarm_cleanup(void) { // If lazy_initialize never ran there is nothing else to do if (!alarms) return; dispatcher_thread_active = false; semaphore_post(alarm_expired); thread_free(dispatcher_thread); dispatcher_thread = NULL; std::lock_guard lock(alarms_mutex); fixed_queue_free(default_callback_queue, NULL); default_callback_queue = NULL; thread_free(default_callback_thread); default_callback_thread = NULL; timer_delete(wakeup_timer); timer_delete(timer); semaphore_free(alarm_expired); alarm_expired = NULL; list_free(alarms); alarms = NULL; } static bool lazy_initialize(void) { CHECK(alarms == NULL); // timer_t doesn't have an invalid value so we must track whether // the |timer| variable is valid ourselves. bool timer_initialized = false; bool wakeup_timer_initialized = false; std::lock_guard lock(alarms_mutex); alarms = list_new(NULL); if (!alarms) { LOG_ERROR("%s unable to allocate alarm list.", __func__); goto error; } if (!timer_create_internal(CLOCK_ID, &timer)) goto error; timer_initialized = true; if (!timer_create_internal(CLOCK_BOOTTIME_ALARM, &wakeup_timer)) { if (!timer_create_internal(CLOCK_BOOTTIME, &wakeup_timer)) { goto error; } } wakeup_timer_initialized = true; alarm_expired = semaphore_new(0); if (!alarm_expired) { LOG_ERROR("%s unable to create alarm expired semaphore", __func__); goto error; } default_callback_thread = thread_new_sized("alarm_default_callbacks", SIZE_MAX); if (default_callback_thread == NULL) { LOG_ERROR("%s unable to create default alarm callbacks thread.", __func__); goto error; } thread_set_rt_priority(default_callback_thread, THREAD_RT_PRIORITY); default_callback_queue = fixed_queue_new(SIZE_MAX); if (default_callback_queue == NULL) { LOG_ERROR("%s unable to create default alarm callbacks queue.", __func__); goto error; } alarm_register_processing_queue(default_callback_queue, default_callback_thread); dispatcher_thread_active = true; dispatcher_thread = thread_new("alarm_dispatcher"); if (!dispatcher_thread) { LOG_ERROR("%s unable to create alarm callback thread.", __func__); goto error; } thread_set_rt_priority(dispatcher_thread, THREAD_RT_PRIORITY); thread_post(dispatcher_thread, callback_dispatch, NULL); return true; error: fixed_queue_free(default_callback_queue, NULL); default_callback_queue = NULL; thread_free(default_callback_thread); default_callback_thread = NULL; thread_free(dispatcher_thread); dispatcher_thread = NULL; dispatcher_thread_active = false; semaphore_free(alarm_expired); alarm_expired = NULL; if (wakeup_timer_initialized) timer_delete(wakeup_timer); if (timer_initialized) timer_delete(timer); list_free(alarms); alarms = NULL; return false; } static uint64_t now_ms(void) { CHECK(alarms != NULL); struct timespec ts; if (clock_gettime(CLOCK_ID, &ts) == -1) { LOG_ERROR("%s unable to get current time: %s", __func__, strerror(errno)); return 0; } return (ts.tv_sec * 1000LL) + (ts.tv_nsec / 1000000LL); } // Remove alarm from internal alarm list and the processing queue // The caller must hold the |alarms_mutex| static void remove_pending_alarm(alarm_t* alarm) { list_remove(alarms, alarm); if (alarm->for_msg_loop) { alarm->closure.i.Cancel(); } else { while (fixed_queue_try_remove_from_queue(alarm->queue, alarm) != NULL) { // Remove all repeated alarm instances from the queue. // NOTE: We are defensive here - we shouldn't have repeated alarm // instances } } } // Must be called with |alarms_mutex| held static void schedule_next_instance(alarm_t* alarm) { // If the alarm is currently set and it's at the start of the list, // we'll need to re-schedule since we've adjusted the earliest deadline. bool needs_reschedule = (!list_is_empty(alarms) && list_front(alarms) == alarm); if (alarm->callback) remove_pending_alarm(alarm); // Calculate the next deadline for this alarm uint64_t just_now_ms = now_ms(); uint64_t ms_into_period = 0; if ((alarm->is_periodic) && (alarm->period_ms != 0)) ms_into_period = ((just_now_ms - alarm->creation_time_ms) % alarm->period_ms); alarm->deadline_ms = just_now_ms + (alarm->period_ms - ms_into_period); // Add it into the timer list sorted by deadline (earliest deadline first). if (list_is_empty(alarms) || ((alarm_t*)list_front(alarms))->deadline_ms > alarm->deadline_ms) { list_prepend(alarms, alarm); } else { for (list_node_t* node = list_begin(alarms); node != list_end(alarms); node = list_next(node)) { list_node_t* next = list_next(node); if (next == list_end(alarms) || ((alarm_t*)list_node(next))->deadline_ms > alarm->deadline_ms) { list_insert_after(alarms, node, alarm); break; } } } // If the new alarm has the earliest deadline, we need to re-evaluate our // schedule. if (needs_reschedule || (!list_is_empty(alarms) && list_front(alarms) == alarm)) { reschedule_root_alarm(); } } // NOTE: must be called with |alarms_mutex| held static void reschedule_root_alarm(void) { CHECK(alarms != NULL); const bool timer_was_set = timer_set; alarm_t* next; int64_t next_expiration; // If used in a zeroed state, disarms the timer. struct itimerspec timer_time; memset(&timer_time, 0, sizeof(timer_time)); if (list_is_empty(alarms)) goto done; next = static_cast(list_front(alarms)); next_expiration = next->deadline_ms - now_ms(); if (next_expiration < TIMER_INTERVAL_FOR_WAKELOCK_IN_MS) { if (!timer_set) { if (!wakelock_acquire()) { LOG_ERROR("%s unable to acquire wake lock", __func__); goto done; } } timer_time.it_value.tv_sec = (next->deadline_ms / 1000); timer_time.it_value.tv_nsec = (next->deadline_ms % 1000) * 1000000LL; // It is entirely unsafe to call timer_settime(2) with a zeroed timerspec // for timers with *_ALARM clock IDs. Although the man page states that the // timer would be canceled, the current behavior (as of Linux kernel 3.17) // is that the callback is issued immediately. The only way to cancel an // *_ALARM timer is to delete the timer. But unfortunately, deleting and // re-creating a timer is rather expensive; every timer_create(2) spawns a // new thread. So we simply set the timer to fire at the largest possible // time. // // If we've reached this code path, we're going to grab a wake lock and // wait for the next timer to fire. In that case, there's no reason to // have a pending wakeup timer so we simply cancel it. struct itimerspec end_of_time; memset(&end_of_time, 0, sizeof(end_of_time)); end_of_time.it_value.tv_sec = (time_t)(1LL << (sizeof(time_t) * 8 - 2)); timer_settime(wakeup_timer, TIMER_ABSTIME, &end_of_time, NULL); } else { // WARNING: do not attempt to use relative timers with *_ALARM clock IDs // in kernels before 3.17 unless you have the following patch: // https://lkml.org/lkml/2014/7/7/576 struct itimerspec wakeup_time; memset(&wakeup_time, 0, sizeof(wakeup_time)); wakeup_time.it_value.tv_sec = (next->deadline_ms / 1000); wakeup_time.it_value.tv_nsec = (next->deadline_ms % 1000) * 1000000LL; if (timer_settime(wakeup_timer, TIMER_ABSTIME, &wakeup_time, NULL) == -1) LOG_ERROR("%s unable to set wakeup timer: %s", __func__, strerror(errno)); } done: timer_set = timer_time.it_value.tv_sec != 0 || timer_time.it_value.tv_nsec != 0; if (timer_was_set && !timer_set) { wakelock_release(); } if (timer_settime(timer, TIMER_ABSTIME, &timer_time, NULL) == -1) LOG_ERROR("%s unable to set timer: %s", __func__, strerror(errno)); // If next expiration was in the past (e.g. short timer that got context // switched) then the timer might have diarmed itself. Detect this case and // work around it by manually signalling the |alarm_expired| semaphore. // // It is possible that the timer was actually super short (a few // milliseconds) and the timer expired normally before we called // |timer_gettime|. Worst case, |alarm_expired| is signaled twice for that // alarm. Nothing bad should happen in that case though since the callback // dispatch function checks to make sure the timer at the head of the list // actually expired. if (timer_set) { struct itimerspec time_to_expire; timer_gettime(timer, &time_to_expire); if (time_to_expire.it_value.tv_sec == 0 && time_to_expire.it_value.tv_nsec == 0) { LOG_INFO( "%s alarm expiration too close for posix timers, switching to guns", __func__); semaphore_post(alarm_expired); } } } static void alarm_register_processing_queue(fixed_queue_t* queue, thread_t* thread) { CHECK(queue != NULL); CHECK(thread != NULL); fixed_queue_register_dequeue(queue, thread_get_reactor(thread), alarm_queue_ready, NULL); } static void alarm_ready_generic(alarm_t* alarm, std::unique_lock& lock) { if (alarm == NULL) { return; // The alarm was probably canceled } // // If the alarm is not periodic, we've fully serviced it now, and can reset // some of its internal state. This is useful to distinguish between expired // alarms and active ones. // if (!alarm->callback) { LOG(FATAL) << __func__ << ": timer callback is NULL! Name=" << alarm->stats.name; } alarm_callback_t callback = alarm->callback; void* data = alarm->data; uint64_t deadline_ms = alarm->deadline_ms; if (alarm->is_periodic) { // The periodic alarm has been rescheduled and alarm->deadline has been // updated, hence we need to use the previous deadline. deadline_ms = alarm->prev_deadline_ms; } else { alarm->deadline_ms = 0; alarm->callback = NULL; alarm->data = NULL; alarm->queue = NULL; } // Increment the reference count of the mutex so it doesn't get freed // before the callback gets finished executing. std::shared_ptr local_mutex_ref = alarm->callback_mutex; std::lock_guard cb_lock(*local_mutex_ref); lock.unlock(); // Update the statistics update_scheduling_stats(&alarm->stats, now_ms(), deadline_ms); // NOTE: Do NOT access "alarm" after the callback, as a safety precaution // in case the callback itself deleted the alarm. callback(data); } static void alarm_ready_mloop(alarm_t* alarm) { std::unique_lock lock(alarms_mutex); alarm_ready_generic(alarm, lock); } static void alarm_queue_ready(fixed_queue_t* queue, UNUSED_ATTR void* context) { CHECK(queue != NULL); std::unique_lock lock(alarms_mutex); alarm_t* alarm = (alarm_t*)fixed_queue_try_dequeue(queue); alarm_ready_generic(alarm, lock); } // Callback function for wake alarms and our posix timer static void timer_callback(UNUSED_ATTR void* ptr) { semaphore_post(alarm_expired); } // Function running on |dispatcher_thread| that performs the following: // (1) Receives a signal using |alarm_exired| that the alarm has expired // (2) Dispatches the alarm callback for processing by the corresponding // thread for that alarm. static void callback_dispatch(UNUSED_ATTR void* context) { while (true) { semaphore_wait(alarm_expired); if (!dispatcher_thread_active) break; std::lock_guard lock(alarms_mutex); alarm_t* alarm; // Take into account that the alarm may get cancelled before we get to it. // We're done here if there are no alarms or the alarm at the front is in // the future. Exit right away since there's nothing left to do. if (list_is_empty(alarms) || (alarm = static_cast(list_front(alarms)))->deadline_ms > now_ms()) { reschedule_root_alarm(); continue; } list_remove(alarms, alarm); if (alarm->is_periodic) { alarm->prev_deadline_ms = alarm->deadline_ms; schedule_next_instance(alarm); alarm->stats.rescheduled_count++; } reschedule_root_alarm(); // Enqueue the alarm for processing if (alarm->for_msg_loop) { if (!get_main_thread()) { LOG_ERROR("%s: message loop already NULL. Alarm: %s", __func__, alarm->stats.name); continue; } alarm->closure.i.Reset(Bind(alarm_ready_mloop, alarm)); get_main_thread()->DoInThread(FROM_HERE, alarm->closure.i.callback()); } else { fixed_queue_enqueue(alarm->queue, alarm); } } LOG_INFO("%s Callback thread exited", __func__); } static bool timer_create_internal(const clockid_t clock_id, timer_t* timer) { CHECK(timer != NULL); struct sigevent sigevent; // create timer with RT priority thread pthread_attr_t thread_attr; pthread_attr_init(&thread_attr); pthread_attr_setschedpolicy(&thread_attr, SCHED_FIFO); struct sched_param param; param.sched_priority = THREAD_RT_PRIORITY; pthread_attr_setschedparam(&thread_attr, ¶m); memset(&sigevent, 0, sizeof(sigevent)); sigevent.sigev_notify = SIGEV_THREAD; sigevent.sigev_notify_function = (void (*)(union sigval))timer_callback; sigevent.sigev_notify_attributes = &thread_attr; if (timer_create(clock_id, &sigevent, timer) == -1) { LOG_ERROR("%s unable to create timer with clock %d: %s", __func__, clock_id, strerror(errno)); if (clock_id == CLOCK_BOOTTIME_ALARM) { LOG_ERROR( "The kernel might not have support for " "timer_create(CLOCK_BOOTTIME_ALARM): " "https://lwn.net/Articles/429925/"); LOG_ERROR( "See following patches: " "https://git.kernel.org/cgit/linux/kernel/git/torvalds/" "linux.git/log/?qt=grep&q=CLOCK_BOOTTIME_ALARM"); } return false; } return true; } static void update_scheduling_stats(alarm_stats_t* stats, uint64_t now_ms, uint64_t deadline_ms) { stats->total_updates++; stats->last_update_ms = now_ms; if (deadline_ms < now_ms) { // Overdue scheduling uint64_t delta_ms = now_ms - deadline_ms; update_stat(&stats->overdue_scheduling, delta_ms); } else if (deadline_ms > now_ms) { // Premature scheduling uint64_t delta_ms = deadline_ms - now_ms; update_stat(&stats->premature_scheduling, delta_ms); } } static void dump_stat(int fd, stat_t* stat, const char* description) { uint64_t average_time_ms = 0; if (stat->count != 0) average_time_ms = stat->total_ms / stat->count; dprintf(fd, "%-51s: %llu / %llu / %llu\n", description, (unsigned long long)stat->total_ms, (unsigned long long)stat->max_ms, (unsigned long long)average_time_ms); } void alarm_debug_dump(int fd) { dprintf(fd, "\nBluetooth Alarms Statistics:\n"); std::lock_guard lock(alarms_mutex); if (alarms == NULL) { dprintf(fd, " None\n"); return; } uint64_t just_now_ms = now_ms(); dprintf(fd, " Total Alarms: %zu\n\n", list_length(alarms)); // Dump info for each alarm for (list_node_t* node = list_begin(alarms); node != list_end(alarms); node = list_next(node)) { alarm_t* alarm = (alarm_t*)list_node(node); alarm_stats_t* stats = &alarm->stats; dprintf(fd, " Alarm : %s (%s)\n", stats->name, (alarm->is_periodic) ? "PERIODIC" : "SINGLE"); dprintf(fd, "%-51s: %zu / %zu / %zu / %zu\n", " Action counts (sched/resched/exec/cancel)", stats->scheduled_count, stats->rescheduled_count, stats->total_updates, stats->canceled_count); dprintf(fd, "%-51s: %zu / %zu\n", " Deviation counts (overdue/premature)", stats->overdue_scheduling.count, stats->premature_scheduling.count); dprintf(fd, "%-51s: %llu / %llu / %lld\n", " Time in ms (since creation/interval/remaining)", (unsigned long long)(just_now_ms - alarm->creation_time_ms), (unsigned long long)alarm->period_ms, (long long)(alarm->deadline_ms - just_now_ms)); dump_stat(fd, &stats->overdue_scheduling, " Overdue scheduling time in ms (total/max/avg)"); dump_stat(fd, &stats->premature_scheduling, " Premature scheduling time in ms (total/max/avg)"); dprintf(fd, "\n"); } }