1use anyhow::{anyhow, Result};
29use fidl::encoding::ProxyChannelBox;
30use fidl::endpoints::RequestStream;
31use fidl::HandleBased;
32use fuchsia_inspect::{HistogramProperty, Property};
33use futures::channel::mpsc;
34use futures::sink::SinkExt;
35use futures::StreamExt;
36use log::{debug, error, warn};
37use scopeguard::defer;
38use std::cell::RefCell;
39use std::cmp;
40use std::collections::{BTreeMap, BinaryHeap, HashMap};
41use std::rc::Rc;
42use std::sync::LazyLock;
43use zx::AsHandleRef;
44use {
45 fidl_fuchsia_hardware_hrtimer as ffhh, fidl_fuchsia_time_alarms as fta,
46 fuchsia_async as fasync, fuchsia_inspect as finspect, fuchsia_trace as trace,
47};
48
49static I64_MAX_AS_U64: LazyLock<u64> = LazyLock::new(|| i64::MAX.try_into().expect("infallible"));
50static I32_MAX_AS_U64: LazyLock<u64> = LazyLock::new(|| i32::MAX.try_into().expect("infallible"));
51
52static MAX_USEFUL_TICKS: LazyLock<u64> = LazyLock::new(|| *I32_MAX_AS_U64);
54
55const MAIN_TIMER_ID: usize = 6;
58
59const TEMPORARY_STARNIX_TIMER_ID: &str = "starnix-hrtimer";
64static TEMPORARY_STARNIX_CID: LazyLock<zx::Event> = LazyLock::new(|| zx::Event::create());
65
66const USEC_IN_NANOS: i64 = 1000;
68const MSEC_IN_NANOS: i64 = 1000 * USEC_IN_NANOS;
69const SEC_IN_NANOS: i64 = 1000 * MSEC_IN_NANOS;
70const MIN_IN_NANOS: i64 = SEC_IN_NANOS * 60;
71const HOUR_IN_NANOS: i64 = MIN_IN_NANOS * 60;
72const DAY_IN_NANOS: i64 = HOUR_IN_NANOS * 24;
73const WEEK_IN_NANOS: i64 = DAY_IN_NANOS * 7;
74const YEAR_IN_NANOS: i64 = DAY_IN_NANOS * 365; static UNITS: LazyLock<Vec<(i64, &'static str)>> = LazyLock::new(|| {
77 vec![
78 (YEAR_IN_NANOS, "year(s)"),
79 (WEEK_IN_NANOS, "week(s)"),
80 (DAY_IN_NANOS, "day(s)"),
81 (HOUR_IN_NANOS, "h"),
82 (MIN_IN_NANOS, "min"),
83 (SEC_IN_NANOS, "s"),
84 (MSEC_IN_NANOS, "ms"),
85 (USEC_IN_NANOS, "μs"),
86 (1, "ns"),
87 ]
88});
89
90fn format_common(mut value: i64) -> String {
93 let value_copy = value;
94 let mut repr: Vec<String> = vec![];
95 for (unit_value, unit_str) in UNITS.iter() {
96 if value == 0 {
97 break;
98 }
99 let num_units = value / unit_value;
100 if num_units.abs() > 0 {
101 repr.push(format!("{}{}", num_units, unit_str));
102 value = value % unit_value;
103 }
104 }
105 if repr.len() == 0 {
106 repr.push("0ns".to_string());
107 }
108 let repr = repr.join("_");
110
111 let mut ret = vec![];
112 ret.push(repr);
113 ret.push(format!("({})", value_copy));
115 ret.join(" ")
116}
117
118fn format_timer<T: zx::Timeline>(timer: zx::Instant<T>) -> String {
120 format_common(timer.into_nanos())
121}
122
123fn format_duration<T: zx::Timeline>(duration: zx::Duration<T>) -> String {
125 format_common(duration.into_nanos())
126}
127
128fn is_deadline_changed(
131 before: Option<fasync::BootInstant>,
132 after: Option<fasync::BootInstant>,
133) -> bool {
134 match (before, after) {
135 (None, None) => false,
136 (None, Some(_)) | (Some(_), None) => true,
137 (Some(before), Some(after)) => before != after,
138 }
139}
140
141async fn stop_hrtimer(hrtimer: &ffhh::DeviceProxy, timer_config: &TimerConfig) {
143 trace::duration!(c"alarms", c"hrtimer:stop", "id" => timer_config.id);
144 debug!("stop_hrtimer: stopping hardware timer: {}", timer_config.id);
145 let _ = hrtimer
146 .stop(timer_config.id)
147 .await
148 .map(|result| {
149 let _ = result.map_err(|e| warn!("stop_hrtimer: driver error: {:?}", e));
150 })
151 .map_err(|e| warn!("stop_hrtimer: could not stop prior timer: {}", e));
152 debug!("stop_hrtimer: stopped hardware timer: {}", timer_config.id);
153}
154
155const CHANNEL_SIZE: usize = 100;
157
158#[derive(Debug)]
160enum Cmd {
161 Start {
163 cid: zx::Koid,
165 deadline: fasync::BootInstant,
167 setup_done: zx::Event,
173 alarm_id: String,
175 responder: Rc<RefCell<Option<fta::WakeSetAndWaitResponder>>>,
183 },
184 StopById {
185 done: zx::Event,
186 timer_id: TimerId,
187 },
188 Alarm {
189 expired_deadline: fasync::BootInstant,
190 keep_alive: fidl::EventPair,
191 },
192 AlarmFidlError {
193 expired_deadline: fasync::BootInstant,
194 error: fidl::Error,
195 },
196 AlarmDriverError {
197 expired_deadline: fasync::BootInstant,
198 error: ffhh::DriverError,
199 },
200}
201
202impl std::fmt::Display for Cmd {
203 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
204 match self {
205 Cmd::Start { cid, deadline, alarm_id, .. } => {
206 write!(
207 f,
208 "Start[alarm_id=\"{}\", cid={:?}, deadline={}]",
209 alarm_id,
210 cid,
211 format_timer((*deadline).into())
212 )
213 }
214 Cmd::Alarm { expired_deadline, .. } => {
215 write!(f, "Alarm[deadline={}]", format_timer((*expired_deadline).into()))
216 }
217 Cmd::AlarmFidlError { expired_deadline, error } => {
218 write!(
219 f,
220 "FIDLError[deadline={}, err={}, NO_WAKE_LEASE!]",
221 format_timer((*expired_deadline).into()),
222 error
223 )
224 }
225 Cmd::AlarmDriverError { expired_deadline, error } => {
226 write!(
227 f,
228 "DriverError[deadline={}, err={:?}, NO_WAKE_LEASE!]",
229 format_timer((*expired_deadline).into()),
230 error
231 )
232 }
233 Cmd::StopById { timer_id, done: _ } => {
234 write!(f, "StopById[timerId={}]", timer_id,)
235 }
236 }
237 }
238}
239
240pub fn get_stream_koid(stream: fta::WakeRequestStream) -> (zx::Koid, fta::WakeRequestStream) {
247 let (inner, is_terminated) = stream.into_inner();
248 let koid = inner.channel().as_channel().get_koid().expect("infallible");
249 let stream = fta::WakeRequestStream::from_inner(inner, is_terminated);
250 (koid, stream)
251}
252
253pub async fn serve(timer_loop: Rc<Loop>, requests: fta::WakeRequestStream) {
255 fasync::Task::local(async move {
257 let timer_loop = timer_loop.clone();
258 let timer_loop_send = || timer_loop.get_sender();
259 let (cid, mut requests) = get_stream_koid(requests);
260 let mut request_count = 0;
261 debug!("alarms::serve: opened connection: {:?}", cid);
262 while let Some(maybe_request) = requests.next().await {
263 request_count += 1;
264 debug!("alarms::serve: cid: {:?} incoming request: {}", cid, request_count);
265 match maybe_request {
266 Ok(request) => {
267 handle_request(cid, timer_loop_send(), request).await;
269 }
270 Err(e) => {
271 warn!("alarms::serve: error in request: {:?}", e);
272 }
273 }
274 debug!("alarms::serve: cid: {:?} done request: {}", cid, request_count);
275 }
276 warn!("alarms::serve: CLOSED CONNECTION: cid: {:?}", cid);
279 })
280 .detach();
281}
282
283fn compute_cid(cid: zx::Koid, alarm_id: &str) -> zx::Koid {
287 if alarm_id == TEMPORARY_STARNIX_TIMER_ID {
288 TEMPORARY_STARNIX_CID.as_handle_ref().get_koid().expect("infallible")
291 } else {
292 cid
293 }
294}
295
296async fn handle_cancel(alarm_id: String, cid: zx::Koid, cmd: &mut mpsc::Sender<Cmd>) {
297 let done = zx::Event::create();
298 let cid = compute_cid(cid, &alarm_id);
299 let timer_id = TimerId { alarm_id: alarm_id.clone(), cid };
300 if let Err(e) = cmd.send(Cmd::StopById { timer_id, done: clone_handle(&done) }).await {
301 warn!("handle_request: error while trying to cancel: {}: {:?}", alarm_id, e);
302 }
303 wait_signaled(&done).await;
304}
305
306async fn handle_request(cid: zx::Koid, mut cmd: mpsc::Sender<Cmd>, request: fta::WakeRequest) {
314 match request {
315 fta::WakeRequest::SetAndWait { deadline, setup_done, alarm_id, responder } => {
316 let responder = Rc::new(RefCell::new(Some(responder)));
326 let cid = compute_cid(cid, &alarm_id);
327
328 debug!(
330 "handle_request: scheduling alarm_id: \"{}\"\n\tcid: {:?}\n\tdeadline: {}",
331 alarm_id,
332 cid,
333 format_timer(deadline.into())
334 );
335 if let Err(e) = cmd
337 .send(Cmd::Start {
338 cid,
339 deadline: deadline.into(),
340 setup_done,
341 alarm_id: alarm_id.clone(),
342 responder: responder.clone(),
343 })
344 .await
345 {
346 warn!("handle_request: error while trying to schedule `{}`: {:?}", alarm_id, e);
347 responder
348 .borrow_mut()
349 .take()
350 .expect("always present if call fails")
351 .send(Err(fta::WakeError::Internal))
352 .unwrap();
353 }
354 }
355 fta::WakeRequest::Cancel { alarm_id, .. } => {
356 handle_cancel(alarm_id, cid, &mut cmd).await;
359 }
360 fta::WakeRequest::CancelSync { alarm_id, responder, .. } => {
362 handle_cancel(alarm_id, cid, &mut cmd).await;
363 responder.send(Ok(())).expect("infallible");
364 }
365 fta::WakeRequest::GetProperties { responder, .. } => {
366 let response =
367 fta::WakeGetPropertiesResponse { is_supported: Some(true), ..Default::default() };
368 debug!("sending: Wake.GetProperties: {:?}", &response);
369 responder.send(&response).expect("send success");
370 }
371 fta::WakeRequest::_UnknownMethod { .. } => {}
372 };
373}
374
375pub struct Loop {
379 _task: fasync::Task<()>,
381 snd_cloneable: mpsc::Sender<Cmd>,
384}
385
386impl Loop {
387 pub fn new(device_proxy: ffhh::DeviceProxy, inspect: finspect::Node) -> Self {
391 let (snd, rcv) = mpsc::channel(CHANNEL_SIZE);
392 let snd_clone = snd.clone();
393 let _task = fasync::Task::local(async move {
394 wake_timer_loop(snd_clone, rcv, device_proxy, inspect).await
395 });
396 Self { _task, snd_cloneable: snd }
397 }
398
399 fn get_sender(&self) -> mpsc::Sender<Cmd> {
402 self.snd_cloneable.clone()
403 }
404}
405
406#[derive(Debug)]
408struct TimerNode {
409 deadline: fasync::BootInstant,
411 alarm_id: String,
413 cid: zx::Koid,
416 responder: Option<fta::WakeSetAndWaitResponder>,
419}
420
421impl TimerNode {
422 fn new(
423 deadline: fasync::BootInstant,
424 alarm_id: String,
425 cid: zx::Koid,
426 responder: fta::WakeSetAndWaitResponder,
427 ) -> Self {
428 Self { deadline, alarm_id, cid, responder: Some(responder) }
429 }
430
431 fn get_alarm_id(&self) -> &str {
432 &self.alarm_id[..]
433 }
434
435 fn get_cid(&self) -> &zx::Koid {
436 &self.cid
437 }
438
439 fn get_id(&self) -> TimerId {
440 TimerId { alarm_id: self.alarm_id.clone(), cid: self.cid.clone() }
441 }
442
443 fn get_deadline(&self) -> &fasync::BootInstant {
444 &self.deadline
445 }
446
447 fn take_responder(&mut self) -> Option<fta::WakeSetAndWaitResponder> {
448 self.responder.take()
449 }
450}
451
452impl Drop for TimerNode {
453 fn drop(&mut self) {
456 let responder = self.take_responder();
457 responder.map(|r| {
458 r.send(Err(fta::WakeError::Dropped))
462 .map_err(|e| error!("could not drop responder: {:?}", e))
463 });
464 }
465}
466
467impl std::cmp::Eq for TimerNode {}
470
471impl std::cmp::PartialEq for TimerNode {
472 fn eq(&self, other: &Self) -> bool {
473 self.deadline == other.deadline && self.alarm_id == other.alarm_id && self.cid == other.cid
474 }
475}
476
477impl std::cmp::PartialOrd for TimerNode {
478 fn partial_cmp(&self, other: &Self) -> Option<cmp::Ordering> {
481 Some(self.cmp(other))
482 }
483}
484
485impl Ord for TimerNode {
486 fn cmp(&self, other: &Self) -> std::cmp::Ordering {
490 let ordering = other.deadline.cmp(&self.deadline);
491 if ordering == std::cmp::Ordering::Equal {
492 let ordering = self.alarm_id.cmp(&self.alarm_id);
493 if ordering == std::cmp::Ordering::Equal {
494 self.cid.cmp(&other.cid)
495 } else {
496 ordering
497 }
498 } else {
499 ordering
500 }
501 }
502}
503
504#[derive(Debug, PartialEq, Eq, Hash)]
506struct TimerId {
507 alarm_id: String,
509 cid: zx::Koid,
511}
512
513impl std::fmt::Display for TimerId {
514 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
515 write!(f, "TimerId[alarm_id:{},cid:{:?}]", self.alarm_id, self.cid)
516 }
517}
518
519struct Timers {
525 timers: BinaryHeap<TimerNode>,
526 deadline_by_id: HashMap<TimerId, fasync::BootInstant>,
527}
528
529impl std::fmt::Display for Timers {
530 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
531 let now = fasync::BootInstant::now();
532 let sorted = self
533 .timers
534 .iter()
535 .map(|n| (n.deadline, n.alarm_id.clone()))
536 .collect::<BTreeMap<_, _>>()
537 .into_iter()
538 .map(|(k, v)| {
539 let remaining = k - now;
540 format!(
541 "Timeout: {} => timer_id: {}, remaining: {}",
542 format_timer(k.into()),
543 v,
544 format_duration(remaining.into())
545 )
546 })
547 .collect::<Vec<_>>();
548 let joined = sorted.join("\n\t");
549 write!(f, "\n\t{}", joined)
550 }
551}
552
553impl Timers {
554 fn new() -> Self {
556 Self { timers: BinaryHeap::new(), deadline_by_id: HashMap::new() }
557 }
558
559 fn push(&mut self, n: TimerNode) {
565 let new_id = n.get_id();
566 if let Some(deadline) = self.deadline_by_id.get(&new_id) {
567 if n.deadline == *deadline {
569 return;
570 }
571 self.deadline_by_id.insert(new_id, n.deadline.clone());
573 self.timers.retain(|t| t.get_id() != n.get_id());
574 self.timers.push(n);
575 } else {
576 self.deadline_by_id.insert(new_id, n.deadline);
578 self.timers.push(n);
579 }
580 }
581
582 fn peek(&self) -> Option<&TimerNode> {
584 self.timers.peek()
585 }
586
587 fn peek_deadline(&self) -> Option<fasync::BootInstant> {
589 self.peek().map(|t| t.deadline)
590 }
591
592 fn peek_id(&self) -> Option<TimerId> {
593 self.peek().map(|t| TimerId { alarm_id: t.alarm_id.clone(), cid: t.cid })
594 }
595
596 fn expired(now: fasync::BootInstant, deadline: fasync::BootInstant) -> bool {
600 deadline <= now
601 }
602
603 fn is_empty(&self) -> bool {
605 let empty1 = self.timers.is_empty();
606 let empty2 = self.deadline_by_id.is_empty();
607 assert!(empty1 == empty2, "broken invariant: empty1: {} empty2:{}", empty1, empty2);
608 empty1
609 }
610
611 fn maybe_expire_earliest(&mut self, now: fasync::BootInstant) -> Option<TimerNode> {
622 self.peek_deadline()
623 .map(|d| {
624 if Timers::expired(now, d) {
625 self.timers.pop().map(|e| {
626 self.deadline_by_id.remove(&e.get_id());
627 e
628 })
629 } else {
630 None
631 }
632 })
633 .flatten()
634 }
635
636 fn remove_by_id(&mut self, timer_id: &TimerId) -> Option<TimerNode> {
639 let ret = if let Some(t) = self.peek_id() {
640 if t == *timer_id {
641 self.timers.pop()
642 } else {
643 None
644 }
645 } else {
646 None
647 };
648
649 self.timers.retain(|t| t.alarm_id != timer_id.alarm_id || t.cid != timer_id.cid);
650 self.deadline_by_id.remove(timer_id);
651 ret
652 }
653
654 fn timer_count(&self) -> usize {
656 let count1 = self.timers.len();
657 let count2 = self.deadline_by_id.len();
658 assert!(count1 == count2, "broken invariant: count1: {}, count2: {}", count1, count2);
659 count1
660 }
661}
662
663fn clone_handle<H: HandleBased>(handle: &H) -> H {
665 handle.duplicate_handle(zx::Rights::SAME_RIGHTS).expect("infallible")
666}
667
668async fn wait_signaled<H: HandleBased>(handle: &H) {
669 fasync::OnSignals::new(handle, zx::Signals::EVENT_SIGNALED).await.expect("infallible");
670}
671
672fn signal<H: HandleBased>(handle: &H) {
673 handle.signal_handle(zx::Signals::NONE, zx::Signals::EVENT_SIGNALED).expect("infallible");
674}
675
676#[derive(Debug, Clone, Copy)]
684struct TimerDuration {
685 resolution: zx::BootDuration,
687 ticks: u64,
690}
691
692impl Eq for TimerDuration {}
695
696impl std::cmp::PartialOrd for TimerDuration {
697 fn partial_cmp(&self, other: &TimerDuration) -> Option<std::cmp::Ordering> {
698 Some(self.cmp(other))
699 }
700}
701
702impl std::cmp::PartialEq for TimerDuration {
703 fn eq(&self, other: &Self) -> bool {
704 self.cmp(other) == std::cmp::Ordering::Equal
705 }
706}
707
708impl std::cmp::Ord for TimerDuration {
709 fn cmp(&self, other: &TimerDuration) -> std::cmp::Ordering {
712 let self_nanos = self.resolution_as_nanos() * self.ticks;
713 let other_nanos = other.resolution_as_nanos() * other.ticks;
714 self_nanos.cmp(&other_nanos)
715 }
716}
717
718impl std::fmt::Display for TimerDuration {
719 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
723 let ticks = self.ticks;
724 let resolution = self.resolution();
725 write!(f, "{}x{}", ticks, format_duration(resolution),)
727 }
728}
729
730impl TimerDuration {
731 fn max() -> Self {
733 TimerDuration::new(zx::BootDuration::from_nanos(1), *I64_MAX_AS_U64)
734 }
735
736 fn zero() -> Self {
738 TimerDuration::new(zx::BootDuration::from_nanos(1), 0)
739 }
740
741 fn new(resolution: zx::BootDuration, ticks: u64) -> Self {
743 Self { resolution, ticks }
744 }
745
746 fn new_with_resolution(res_source: &TimerDuration, ticks: u64) -> Self {
749 Self::new(res_source.resolution, ticks)
750 }
751
752 fn duration(&self) -> zx::BootDuration {
757 let duration_as_nanos = self.resolution_as_nanos() * self.ticks;
758 let clamp_duration = std::cmp::min(*I32_MAX_AS_U64, duration_as_nanos);
759 zx::BootDuration::from_nanos(clamp_duration.try_into().expect("result was clamped"))
760 }
761
762 fn resolution(&self) -> zx::BootDuration {
764 self.resolution
765 }
766
767 fn resolution_as_nanos(&self) -> u64 {
768 self.resolution().into_nanos().try_into().expect("resolution is never negative")
769 }
770
771 fn ticks(&self) -> u64 {
773 self.ticks
774 }
775}
776
777impl From<zx::BootDuration> for TimerDuration {
778 fn from(d: zx::BootDuration) -> TimerDuration {
779 let nanos = d.into_nanos();
780 assert!(nanos >= 0);
781 let nanos_u64 = nanos.try_into().expect("guarded by assert");
782 TimerDuration::new(zx::BootDuration::from_nanos(1), nanos_u64)
783 }
784}
785
786impl std::ops::Div for TimerDuration {
787 type Output = u64;
788 fn div(self, rhs: Self) -> Self::Output {
789 let self_nanos = self.resolution_as_nanos() * self.ticks;
790 let rhs_nanos = rhs.resolution_as_nanos() * rhs.ticks;
791 self_nanos / rhs_nanos
792 }
793}
794
795impl std::ops::Mul<u64> for TimerDuration {
796 type Output = Self;
797 fn mul(self, rhs: u64) -> Self::Output {
798 Self::new(self.resolution, self.ticks * rhs)
799 }
800}
801
802#[derive(Debug)]
804struct TimerConfig {
805 resolutions: Vec<zx::BootDuration>,
809 max_ticks: u64,
814 id: u64,
816}
817
818impl TimerConfig {
819 fn new_from_data(timer_id: u64, resolutions: &[zx::BootDuration], max_ticks: u64) -> Self {
822 debug!(
823 "TimerConfig: resolutions: {:?}, max_ticks: {}, timer_id: {}",
824 resolutions.iter().map(|r| format_duration(*r)).collect::<Vec<_>>(),
825 max_ticks,
826 timer_id
827 );
828 let resolutions = resolutions.iter().map(|d| *d).collect::<Vec<zx::BootDuration>>();
829 TimerConfig { resolutions, max_ticks, id: timer_id }
830 }
831
832 fn new_empty() -> Self {
833 error!("TimerConfig::new_empty() called, this is not OK.");
834 TimerConfig { resolutions: vec![], max_ticks: 0, id: 0 }
835 }
836
837 fn pick_setting(&self, duration: zx::BootDuration) -> TimerDuration {
847 let mut best_positive_slack = TimerDuration::zero();
854 let mut best_negative_slack = TimerDuration::max();
855
856 if self.max_ticks == 0 {
857 return TimerDuration::new(zx::BootDuration::from_millis(1), 0);
858 }
859 let duration_slack: TimerDuration = duration.into();
860
861 for res1 in self.resolutions.iter() {
862 let smallest_unit = TimerDuration::new(*res1, 1);
863 let max_tick_at_res = TimerDuration::new(*res1, self.max_ticks);
864
865 let smallest_slack_larger_than_duration = smallest_unit > duration_slack;
866 let largest_slack_smaller_than_duration = max_tick_at_res < duration_slack;
867
868 if smallest_slack_larger_than_duration {
869 if smallest_unit < best_negative_slack {
870 best_negative_slack = smallest_unit;
871 }
872 }
873 if largest_slack_smaller_than_duration {
874 if max_tick_at_res > best_positive_slack
875 || best_positive_slack == TimerDuration::zero()
876 {
877 best_positive_slack = max_tick_at_res;
878 }
879 }
880
881 if !smallest_slack_larger_than_duration && !largest_slack_smaller_than_duration {
883 let q = duration_slack / smallest_unit;
886 let d = smallest_unit * q;
887 if d == duration_slack {
888 return d;
890 } else {
891 if d > best_positive_slack {
893 best_positive_slack = TimerDuration::new_with_resolution(&smallest_unit, q);
894 }
895 let d_plus = TimerDuration::new_with_resolution(&smallest_unit, q + 1);
896 if d_plus < best_negative_slack {
897 best_negative_slack = d_plus;
898 }
899 }
900 }
901 }
902
903 let p_slack = duration - best_positive_slack.duration();
904 let n_slack = best_negative_slack.duration() - duration;
905
906 let ret = if p_slack < n_slack && best_positive_slack.duration().into_nanos() > 0 {
911 best_positive_slack
912 } else {
913 best_negative_slack
914 };
915 debug!("TimerConfig: picked slack: {} for duration: {}", ret, format_duration(duration));
916 assert!(
917 ret.duration().into_nanos() > 0,
918 "ret: {}, p_slack: {}, n_slack: {}, orig.duration: {}\n\tbest_p_slack: {}\n\tbest_n_slack: {}\n\ttarget: {}\n\t 1: {} 2: {:?}, 3: {:?}",
919 ret,
920 format_duration(p_slack),
921 format_duration(n_slack),
922 format_duration(duration),
923 best_positive_slack,
924 best_negative_slack,
925 duration_slack,
926 p_slack != zx::BootDuration::ZERO,
927 p_slack,
928 zx::BootDuration::ZERO,
929 );
930 ret
931 }
932}
933
934async fn get_timer_properties(hrtimer: &ffhh::DeviceProxy) -> TimerConfig {
935 debug!("get_timer_properties: requesting timer properties.");
936 match hrtimer.get_properties().await {
937 Ok(p) => {
938 let timers_properties = &p.timers_properties.expect("timers_properties must exist");
939 debug!("get_timer_properties: got: {:?}", timers_properties);
940
941 let timer_index = if timers_properties.len() > MAIN_TIMER_ID {
943 MAIN_TIMER_ID
946 } else if timers_properties.len() > 0 {
947 0
951 } else {
952 return TimerConfig::new_empty();
954 };
955 let main_timer_properties = &timers_properties[timer_index];
956 debug!("alarms: main_timer_properties: {:?}", main_timer_properties);
957 let max_ticks: u64 = std::cmp::min(
959 main_timer_properties.max_ticks.unwrap_or(*MAX_USEFUL_TICKS),
960 *MAX_USEFUL_TICKS,
961 );
962 let resolutions = &main_timer_properties
963 .supported_resolutions
964 .as_ref()
965 .expect("supported_resolutions is populated")
966 .iter()
967 .last() .map(|r| match *r {
969 ffhh::Resolution::Duration(d) => d,
970 _ => {
971 error!(
972 "get_timer_properties: Unknown resolution type, returning millisecond."
973 );
974 MSEC_IN_NANOS
975 }
976 })
977 .map(|d| zx::BootDuration::from_nanos(d))
978 .into_iter() .collect::<Vec<_>>();
980 let timer_id = main_timer_properties.id.expect("timer ID is always present");
981 TimerConfig::new_from_data(timer_id, resolutions, max_ticks)
982 }
983 Err(e) => {
984 error!("could not get timer properties: {:?}", e);
985 TimerConfig::new_empty()
986 }
987 }
988}
989
990struct TimerState {
992 task: fasync::Task<()>,
994 deadline: fasync::BootInstant,
996}
997
998async fn wake_timer_loop(
1007 snd: mpsc::Sender<Cmd>,
1008 mut cmds: mpsc::Receiver<Cmd>,
1009 timer_proxy: ffhh::DeviceProxy,
1010 inspect: finspect::Node,
1011) {
1012 debug!("wake_timer_loop: started");
1013
1014 let mut timers = Timers::new();
1015 let timer_config = get_timer_properties(&timer_proxy).await;
1016
1017 #[allow(clippy::collection_is_never_read)]
1020 let mut hrtimer_status: Option<TimerState> = None;
1021
1022 let now_prop = inspect.create_int("now_ns", 0);
1029 let now_formatted_prop = inspect.create_string("now_formatted", "");
1030 let pending_timers_count_prop = inspect.create_uint("pending_timers_count", 0);
1031 let pending_timers_prop = inspect.create_string("pending_timers", "");
1032 let deadline_histogram_prop = inspect.create_int_exponential_histogram(
1033 "requested_deadlines_ns",
1034 finspect::ExponentialHistogramParams {
1035 floor: 0,
1036 initial_step: zx::BootDuration::from_micros(1).into_nanos(),
1037 step_multiplier: 10,
1039 buckets: 16,
1040 },
1041 );
1042 let hw_node = inspect.create_child("hardware");
1044 let current_hw_deadline_prop = hw_node.create_string("current_deadline", "");
1045 let remaining_until_alarm_prop = hw_node.create_string("remaining_until_alarm", "");
1046
1047 while let Some(cmd) = cmds.next().await {
1048 trace::duration!(c"alarms", c"Cmd");
1049 let now = fasync::BootInstant::now();
1051 now_prop.set(now.into_nanos());
1052 trace::instant!(c"alarms", c"wake_timer_loop", trace::Scope::Process, "now" => now.into_nanos());
1053 match cmd {
1054 Cmd::Start { cid, deadline, setup_done, alarm_id, responder } => {
1055 trace::duration!(c"alarms", c"Cmd::Start");
1056 let responder = responder.borrow_mut().take().expect("responder is always present");
1057 debug!(
1059 "wake_timer_loop: START alarm_id: \"{}\", cid: {:?}\n\tdeadline: {}\n\tnow: {}",
1060 alarm_id,
1061 cid,
1062 format_timer(deadline.into()),
1063 format_timer(now.into()),
1064 );
1065 defer! {
1066 signal(&setup_done);
1068 debug!("wake_timer_loop: START: setup_done signaled");
1069 };
1070 deadline_histogram_prop.insert((deadline - now).into_nanos());
1071 if Timers::expired(now, deadline) {
1072 trace::duration!(c"alarms", c"Cmd::Start:immediate");
1073 let (_lease, keep_alive) = zx::EventPair::create();
1075 debug!(
1076 "[{}] wake_timer_loop: bogus lease {:?}",
1077 line!(),
1078 &keep_alive.get_koid().unwrap()
1079 );
1080 responder
1081 .send(Ok(keep_alive))
1082 .map(|_| {
1083 debug!(
1084 concat!(
1085 "wake_timer_loop: cid: {:?}, alarm: {}: EXPIRED IMMEDIATELY\n\t",
1086 "deadline({}) <= now({})"
1087 ),
1088 cid,
1089 alarm_id,
1090 format_timer(deadline.into()),
1091 format_timer(now.into())
1092 )
1093 })
1094 .map_err(|e| {
1095 error!(
1096 "wake_timer_loop: cid: {:?}, alarm: {}: could not notify, dropping: {}",
1097 cid, alarm_id, e)
1098 })
1099 .unwrap_or(());
1100 } else {
1101 trace::duration!(c"alarms", c"Cmd::Start:regular");
1102 let was_empty = timers.is_empty();
1104
1105 let deadline_before = timers.peek_deadline();
1106 timers.push(TimerNode::new(deadline, alarm_id, cid, responder));
1107 let deadline_after = timers.peek_deadline();
1108
1109 let deadline_changed = is_deadline_changed(deadline_before, deadline_after);
1110 let needs_cancel = !was_empty && deadline_changed;
1111 let needs_reschedule = was_empty || deadline_changed;
1112
1113 if needs_reschedule {
1114 let schedulable_deadline = deadline_after.unwrap_or(deadline);
1116 if needs_cancel {
1117 stop_hrtimer(&timer_proxy, &timer_config).await;
1118 }
1119 hrtimer_status = Some(
1120 schedule_hrtimer(
1121 now,
1122 &timer_proxy,
1123 schedulable_deadline,
1124 snd.clone(),
1125 &timer_config,
1126 )
1127 .await,
1128 );
1129 }
1130 }
1131 }
1132 Cmd::StopById { timer_id, done } => {
1133 trace::duration!(c"alarms", c"Cmd::StopById", "alarm_id" => &timer_id.alarm_id[..]);
1134 debug!("wake_timer_loop: STOP timer: {}", timer_id);
1135 let deadline_before = timers.peek_deadline();
1136
1137 if let Some(mut timer_node) = timers.remove_by_id(&timer_id) {
1138 let deadline_after = timers.peek_deadline();
1139
1140 if let Some(responder) = timer_node.take_responder() {
1141 responder.send(Err(fta::WakeError::Dropped)).expect("infallible");
1143 }
1144 if is_deadline_changed(deadline_before, deadline_after) {
1145 stop_hrtimer(&timer_proxy, &timer_config).await;
1146 }
1147 if let Some(deadline) = deadline_after {
1148 let new_timer_state = schedule_hrtimer(
1151 now,
1152 &timer_proxy,
1153 deadline,
1154 snd.clone(),
1155 &timer_config,
1156 )
1157 .await;
1158 let old_hrtimer_status = hrtimer_status.replace(new_timer_state);
1159 if let Some(task) = old_hrtimer_status.map(|ev| ev.task) {
1160 task.await;
1162 }
1163 } else {
1164 hrtimer_status = None;
1166 }
1167 } else {
1168 debug!("wake_timer_loop: STOP: no active timer to stop: {}", timer_id);
1169 }
1170 signal(&done);
1171 }
1172 Cmd::Alarm { expired_deadline, keep_alive } => {
1173 trace::duration!(c"alarms", c"Cmd::Alarm");
1174 debug!(
1179 "wake_timer_loop: ALARM!!! reached deadline: {}, wakey-wakey! {:?}",
1180 format_timer(expired_deadline.into()),
1181 keep_alive.get_koid().unwrap(),
1182 );
1183 let expired_count =
1184 notify_all(&mut timers, &keep_alive, now).expect("notification succeeds");
1185 if expired_count == 0 {
1186 debug!("wake_timer_loop: no expired alarms, reset hrtimer state");
1189 stop_hrtimer(&timer_proxy, &timer_config).await;
1190 }
1191 hrtimer_status = match timers.peek_deadline() {
1193 None => None,
1194 Some(deadline) => Some(
1195 schedule_hrtimer(now, &timer_proxy, deadline, snd.clone(), &timer_config)
1196 .await,
1197 ),
1198 }
1199 }
1200 Cmd::AlarmFidlError { expired_deadline, error } => {
1201 trace::duration!(c"alarms", c"Cmd::AlarmFidlError");
1202 warn!(
1206 "wake_timer_loop: FIDL error: {:?}, deadline: {}, now: {}",
1207 error,
1208 format_timer(expired_deadline.into()),
1209 format_timer(now.into()),
1210 );
1211 let (_dummy_lease, peer) = zx::EventPair::create();
1214 debug!("XXX: [{}] bogus lease: 1 {:?}", line!(), &peer.get_koid().unwrap());
1215 notify_all(&mut timers, &peer, now).expect("notification succeeds");
1216 hrtimer_status = match timers.peek_deadline() {
1217 None => None, Some(deadline) => Some(
1219 schedule_hrtimer(now, &timer_proxy, deadline, snd.clone(), &timer_config)
1220 .await,
1221 ),
1222 }
1223 }
1224 Cmd::AlarmDriverError { expired_deadline, error } => {
1225 trace::duration!(c"alarms", c"Cmd::AlarmDriverError");
1226 let (_dummy_lease, peer) = zx::EventPair::create();
1227 debug!("XXX: [{}] bogus lease: {:?}", line!(), &peer.get_koid().unwrap());
1228 notify_all(&mut timers, &peer, now).expect("notification succeeds");
1229 match error {
1230 fidl_fuchsia_hardware_hrtimer::DriverError::Canceled => {
1231 debug!(
1233 "wake_timer_loop: CANCELED timer at deadline: {}",
1234 format_timer(expired_deadline.into())
1235 );
1236 }
1237 _ => {
1238 error!(
1239 "wake_timer_loop: DRIVER SAYS: {:?}, deadline: {}, now: {}",
1240 error,
1241 format_timer(expired_deadline.into()),
1242 format_timer(now.into()),
1243 );
1244 hrtimer_status = match timers.peek_deadline() {
1248 None => None,
1249 Some(deadline) => Some(
1250 schedule_hrtimer(
1251 now,
1252 &timer_proxy,
1253 deadline,
1254 snd.clone(),
1255 &timer_config,
1256 )
1257 .await,
1258 ),
1259 }
1260 }
1261 }
1262 }
1263 }
1264
1265 {
1266 trace::duration!(c"timekeeper", c"inspect");
1271 let now_formatted = format_timer(now.into());
1272 debug!("wake_timer_loop: now: {}", &now_formatted);
1273 now_formatted_prop.set(&now_formatted);
1274
1275 let pending_timers_count: u64 =
1276 timers.timer_count().try_into().expect("always convertible");
1277 debug!("wake_timer_loop: currently pending timer count: {}", pending_timers_count);
1278 pending_timers_count_prop.set(pending_timers_count);
1279
1280 let pending_timers = format!("{}", timers);
1281 debug!("wake_timer_loop: currently pending timers: {}", &timers);
1282 pending_timers_prop.set(&pending_timers);
1283
1284 let current_deadline: String = hrtimer_status
1285 .as_ref()
1286 .map(|s| format!("{}", format_timer(s.deadline.into())))
1287 .unwrap_or_else(|| "(none)".into());
1288 debug!("wake_timer_loop: current hardware timer deadline: {:?}", current_deadline);
1289 current_hw_deadline_prop.set(¤t_deadline);
1290
1291 let remaining_duration_until_alarm = hrtimer_status
1292 .as_ref()
1293 .map(|s| format!("{}", format_duration((s.deadline - now).into())))
1294 .unwrap_or_else(|| "(none)".into());
1295 debug!(
1296 "wake_timer_loop: remaining duration until alarm: {}",
1297 &remaining_duration_until_alarm
1298 );
1299 remaining_until_alarm_prop.set(&remaining_duration_until_alarm);
1300 debug!("---");
1301 }
1302 }
1303
1304 debug!("wake_timer_loop: exiting. This is unlikely in prod code.");
1305}
1306
1307async fn schedule_hrtimer(
1318 now: fasync::BootInstant,
1319 hrtimer: &ffhh::DeviceProxy,
1320 deadline: fasync::BootInstant,
1321 mut command_send: mpsc::Sender<Cmd>,
1322 timer_config: &TimerConfig,
1323) -> TimerState {
1324 let timeout = deadline - now;
1325 trace::duration!(c"alarms", c"schedule_hrtimer", "timeout" => timeout.into_nanos());
1326 assert!(
1327 now < deadline,
1328 "now: {}, deadline: {}, diff: {}",
1329 format_timer(now.into()),
1330 format_timer(deadline.into()),
1331 format_duration(timeout),
1332 );
1333 let hrtimer_scheduled = zx::Event::create();
1335
1336 debug!(
1337 "schedule_hrtimer:\n\tnow: {}\n\tdeadline: {}\n\ttimeout: {}",
1338 format_timer(now.into()),
1339 format_timer(deadline.into()),
1340 format_duration(timeout),
1341 );
1342
1343 let slack = timer_config.pick_setting(timeout);
1344
1345 let resolution_nanos = slack.resolution.into_nanos();
1346 let ticks = slack.ticks();
1347 trace::instant!(c"alarms", c"hrtimer:programmed",
1348 trace::Scope::Process,
1349 "resolution_ns" => resolution_nanos,
1350 "ticks" => ticks
1351 );
1352 let start_and_wait_fut = hrtimer.start_and_wait(
1353 timer_config.id,
1354 &ffhh::Resolution::Duration(resolution_nanos),
1355 ticks,
1356 clone_handle(&hrtimer_scheduled),
1357 );
1358 let hrtimer_task = fasync::Task::local(async move {
1359 debug!("hrtimer_task: waiting for hrtimer driver response");
1360 trace::instant!(c"alarms", c"hrtimer:started", trace::Scope::Process);
1361 let response = start_and_wait_fut.await;
1362 trace::instant!(c"alarms", c"hrtimer:response", trace::Scope::Process);
1363 match response {
1364 Err(e) => {
1365 trace::instant!(c"alarms", c"hrtimer:response:fidl_error", trace::Scope::Process);
1366 debug!("hrtimer_task: hrtimer FIDL error: {:?}", e);
1367 command_send
1368 .start_send(Cmd::AlarmFidlError { expired_deadline: now, error: e })
1369 .unwrap();
1370 }
1372 Ok(Err(e)) => {
1373 let driver_error_str = format!("{:?}", e);
1374 trace::instant!(c"alarms", c"hrtimer:response:driver_error", trace::Scope::Process, "error" => &driver_error_str[..]);
1375 debug!("schedule_hrtimer: hrtimer driver error: {:?}", e);
1376 command_send
1377 .start_send(Cmd::AlarmDriverError { expired_deadline: now, error: e })
1378 .unwrap();
1379 }
1381 Ok(Ok(keep_alive)) => {
1382 trace::instant!(c"alarms", c"hrtimer:response:alarm", trace::Scope::Process);
1383 debug!("hrtimer: got alarm response: {:?}", keep_alive);
1384 command_send
1386 .start_send(Cmd::Alarm { expired_deadline: deadline, keep_alive })
1387 .unwrap();
1388 }
1389 }
1390 debug!("hrtimer_task: exiting task.");
1391 trace::instant!(c"alarms", c"hrtimer:task_exit", trace::Scope::Process);
1392 });
1393 debug!("schedule_hrtimer: waiting for event to be signaled");
1394
1395 wait_signaled(&hrtimer_scheduled).await;
1397 debug!("schedule_hrtimer: hrtimer wake alarm has been scheduled.");
1398 TimerState { task: hrtimer_task, deadline }
1399}
1400
1401fn notify_all(
1411 timers: &mut Timers,
1412 lease_prototype: &zx::EventPair,
1413 reference_instant: fasync::BootInstant,
1414) -> Result<usize> {
1415 trace::duration!(c"alarms", c"notify_all");
1416 let now = fasync::BootInstant::now();
1417 let mut expired = 0;
1418 while let Some(mut timer_node) = timers.maybe_expire_earliest(reference_instant) {
1419 expired += 1;
1420 let deadline = *timer_node.get_deadline();
1422 let alarm_id = timer_node.get_alarm_id().to_string();
1423 let cid = timer_node.get_cid().clone();
1424 let slack: zx::BootDuration = deadline - now;
1425 debug!(
1426 concat!(
1427 "wake_alarm_loop: ALARM alarm_id: \"{}\"\n\tdeadline: {},\n\tcid: {:?},\n\t",
1428 "reference_instant: {},\n\tnow: {},\n\tslack: {}",
1429 ),
1430 alarm_id,
1431 format_timer(deadline.into()),
1432 cid,
1433 format_timer(reference_instant.into()),
1434 format_timer(now.into()),
1435 format_duration(slack),
1436 );
1437 let lease = clone_handle(lease_prototype);
1438 trace::instant!(c"alarms", c"notify", trace::Scope::Process, "alarm_id" => &alarm_id[..], "cid" => cid);
1439 let _ = timer_node
1440 .take_responder()
1441 .map(|r| r.send(Ok(lease)))
1442 .map_or_else(|| Ok(()), |res| res)
1443 .map_err(|e| error!("could not signal responder: {:?}", e));
1444 trace::instant!(c"alarms", c"notified", trace::Scope::Process);
1445 }
1446 trace::instant!(c"alarms", c"notify", trace::Scope::Process, "expired_count" => expired);
1447 debug!("notify_all: expired count: {}", expired);
1448 Ok(expired)
1449 }
1451
1452const HRTIMER_DIRECTORY: &str = "/dev/class/hrtimer";
1455
1456pub fn connect_to_hrtimer_async() -> Result<ffhh::DeviceProxy> {
1458 debug!("connect_to_hrtimer: trying directory: {}", HRTIMER_DIRECTORY);
1459 let mut dir = std::fs::read_dir(HRTIMER_DIRECTORY)
1460 .map_err(|e| anyhow!("Failed to open hrtimer directory: {e}"))?;
1461 let entry = dir
1462 .next()
1463 .ok_or_else(|| anyhow!("No entry in the hrtimer directory"))?
1464 .map_err(|e| anyhow!("Failed to find hrtimer device: {e}"))?;
1465 let path = entry
1466 .path()
1467 .into_os_string()
1468 .into_string()
1469 .map_err(|e| anyhow!("Failed to parse the device entry path: {e:?}"))?;
1470
1471 let (hrtimer, server_end) = fidl::endpoints::create_proxy::<ffhh::DeviceMarker>();
1472 fdio::service_connect(&path, server_end.into_channel())
1473 .map_err(|e| anyhow!("Failed to open hrtimer device: {e}"))?;
1474
1475 Ok(hrtimer)
1476}
1477
1478#[cfg(test)]
1479mod tests {
1480 use super::*;
1481 use diagnostics_assertions::{assert_data_tree, AnyProperty};
1482 use futures::{select, Future};
1483 use std::task::Poll;
1484 use test_case::test_case;
1485 use test_util::{assert_gt, assert_lt};
1486
1487 fn run_in_fake_time_and_test_context<F, U, T>(
1496 run_for_duration: zx::MonotonicDuration,
1497 test_fn_factory: F,
1498 ) where
1499 F: FnOnce(fta::WakeProxy, finspect::Inspector) -> U, U: Future<Output = T> + 'static, T: 'static,
1502 {
1503 let mut exec = fasync::TestExecutor::new_with_fake_time(); exec.set_fake_time(fasync::MonotonicInstant::from_nanos(0));
1505 let (mut fake_commands_in, fake_commands_out) = mpsc::channel::<FakeCmd>(0);
1506 let (hrtimer_proxy, hrtimer_task) = fake_hrtimer_connection(fake_commands_out);
1507 let inspector = finspect::component::inspector();
1508 let alarms = Rc::new(Loop::new(hrtimer_proxy, inspector.root().create_child("test")));
1509
1510 let (_handle, peer) = zx::EventPair::create();
1511
1512 let done_set_properties = zx::Event::create();
1513 let begin_test = clone_handle(&done_set_properties);
1514 let begin_serve = clone_handle(&done_set_properties);
1515
1516 let mut fake_commands_in_clone = fake_commands_in.clone();
1517 let config_task = async move {
1518 fake_commands_in
1519 .start_send(FakeCmd::SetProperties {
1520 resolutions: vec![zx::Duration::from_nanos(43)],
1521 max_ticks: 100,
1522 keep_alive: peer,
1523 done: clone_handle(&done_set_properties),
1524 })
1525 .unwrap();
1526 };
1527
1528 let (wake_proxy, wake_stream) =
1529 fidl::endpoints::create_proxy_and_stream::<fta::WakeMarker>();
1530
1531 let serving_task = async move {
1532 fasync::OnSignals::new(begin_serve, zx::Signals::EVENT_SIGNALED).await.unwrap();
1533 serve(alarms, wake_stream).await;
1534 };
1535
1536 let seq_fn_fut = test_fn_factory(wake_proxy, inspector.clone());
1537
1538 let test_task = async move {
1539 fasync::OnSignals::new(begin_test, zx::Signals::EVENT_SIGNALED).await.unwrap();
1541
1542 let result = seq_fn_fut.await;
1543
1544 fake_commands_in_clone.start_send(FakeCmd::Exit).unwrap();
1546 result
1547 };
1548
1549 let mut main_fut = fasync::Task::local(async {
1550 let _r = futures::join!(hrtimer_task, config_task, serving_task, test_task);
1551 });
1552 run_in_fake_time(&mut exec, &mut main_fut, run_for_duration);
1553 }
1554
1555 fn run_in_fake_time<F>(
1564 executor: &mut fasync::TestExecutor,
1565 main_fut: &mut F,
1566 total_duration: zx::MonotonicDuration,
1567 ) where
1568 F: Future<Output = ()> + Unpin,
1569 {
1570 const INCREMENT: zx::MonotonicDuration = zx::MonotonicDuration::from_nanos(13);
1571 let mut current = zx::MonotonicDuration::ZERO;
1572 let mut poll_status = Poll::Pending;
1573
1574 while current < (total_duration + INCREMENT) && poll_status == Poll::Pending {
1579 let next = executor.now() + INCREMENT;
1580 executor.set_fake_time(next);
1581 executor.wake_expired_timers();
1582 poll_status = executor.run_until_stalled(main_fut);
1583 current = current + INCREMENT;
1584 }
1585 let now = executor.now();
1586 assert_eq!(
1587 poll_status,
1588 Poll::Ready(()),
1589 "the main future did not complete at {}, perhaps increase total_duration?",
1590 format_timer(now.into())
1591 );
1592 }
1593
1594 #[test_case(0, "0ns (0)" ; "zero")]
1596 #[test_case(1000, "1μs (1000)" ; "1us positive")]
1597 #[test_case(-1000, "-1μs (-1000)"; "1us negative")]
1598 #[test_case(YEAR_IN_NANOS, "1year(s) (31536000000000000)"; "A year")]
1599 #[test_case(YEAR_IN_NANOS + 8 * DAY_IN_NANOS + 1,
1600 "1year(s)_1week(s)_1day(s)_1ns (32227200000000001)" ; "A weird duration")]
1601 #[test_case(2 * HOUR_IN_NANOS + 8 * MIN_IN_NANOS + 32 * SEC_IN_NANOS + 1,
1602 "2h_8min_32s_1ns (7712000000001)" ; "A reasonable long duration")]
1603 fn test_format_common(value: i64, repr: &str) {
1604 assert_eq!(format_common(value), repr.to_string());
1605 }
1606
1607 #[test_case(
1608 TimerDuration::new(zx::BootDuration::from_nanos(1), 1),
1609 TimerDuration::new(zx::BootDuration::from_nanos(1), 1)
1610 )]
1611 #[test_case(
1612 TimerDuration::new(zx::BootDuration::from_nanos(1), 10),
1613 TimerDuration::new(zx::BootDuration::from_nanos(10), 1)
1614 )]
1615 #[test_case(
1616 TimerDuration::new(zx::BootDuration::from_nanos(10), 1),
1617 TimerDuration::new(zx::BootDuration::from_nanos(1), 10)
1618 )]
1619 #[test_case(
1620 TimerDuration::new(zx::BootDuration::from_micros(1), 1),
1621 TimerDuration::new(zx::BootDuration::from_nanos(1), 1000)
1622 )]
1623 fn test_slack_eq(one: TimerDuration, other: TimerDuration) {
1624 assert_eq!(one, other);
1625 }
1626
1627 #[test_case(
1628 TimerDuration::new(zx::BootDuration::from_nanos(1), 1),
1629 TimerDuration::new(zx::BootDuration::from_nanos(1), 2)
1630 )]
1631 #[test_case(
1632 TimerDuration::new(zx::BootDuration::from_nanos(1), 1),
1633 TimerDuration::new(zx::BootDuration::from_nanos(10), 1)
1634 )]
1635 fn test_slack_lt(one: TimerDuration, other: TimerDuration) {
1636 assert_lt!(one, other);
1637 }
1638
1639 #[test_case(
1640 TimerDuration::new(zx::BootDuration::from_nanos(1), 2),
1641 TimerDuration::new(zx::BootDuration::from_nanos(1), 1)
1642 )]
1643 #[test_case(
1644 TimerDuration::new(zx::BootDuration::from_nanos(10), 1),
1645 TimerDuration::new(zx::BootDuration::from_nanos(1), 1)
1646 )]
1647 fn test_slack_gt(one: TimerDuration, other: TimerDuration) {
1648 assert_gt!(one, other);
1649 }
1650
1651 #[test_case(
1652 vec![zx::BootDuration::from_nanos(1)],
1653 100,
1654 zx::BootDuration::from_nanos(50),
1655 TimerDuration::new(zx::BootDuration::from_nanos(1), 50) ; "Exact at 50x1ns"
1656 )]
1657 #[test_case(
1658 vec![zx::BootDuration::from_nanos(2)],
1659 100,
1660 zx::BootDuration::from_nanos(50),
1661 TimerDuration::new(zx::BootDuration::from_nanos(2), 25) ; "Exact at 25x2ns"
1662 )]
1663 #[test_case(
1664 vec![zx::BootDuration::from_nanos(3)],
1665 100,
1666 zx::BootDuration::from_nanos(50),
1667 TimerDuration::new(zx::BootDuration::from_nanos(3), 17) ; "Inexact at 51ns"
1669 )]
1670 #[test_case(
1671 vec![
1672 zx::BootDuration::from_nanos(3),
1673 zx::BootDuration::from_nanos(4)
1674 ],
1675 100,
1676 zx::BootDuration::from_nanos(50),
1677 TimerDuration::new(zx::BootDuration::from_nanos(3), 17) ; "3ns is a better resolution"
1678 )]
1679 #[test_case(
1680 vec![
1681 zx::BootDuration::from_nanos(1000),
1682 ],
1683 100,
1684 zx::BootDuration::from_nanos(50),
1685 TimerDuration::new(zx::BootDuration::from_nanos(1000), 1) ;
1686 "950ns negative slack is the best we can do"
1687 )]
1688 #[test_case(
1689 vec![
1690 zx::BootDuration::from_nanos(1),
1691 ],
1692 10,
1693 zx::BootDuration::from_nanos(50),
1694 TimerDuration::new(zx::BootDuration::from_nanos(1), 10) ;
1695 "10ns positive slack is the best we can do"
1696 )]
1697 #[test_case(
1698 vec![
1699 zx::BootDuration::from_millis(1),
1700 zx::BootDuration::from_micros(100),
1701 zx::BootDuration::from_micros(10),
1702 zx::BootDuration::from_micros(1),
1703 ],
1704 20, zx::BootDuration::from_micros(150),
1706 TimerDuration::new(zx::BootDuration::from_micros(10), 15) ;
1707 "Realistic case with resolutions from driver, should be 15us"
1708 )]
1709 #[test_case(
1710 vec![
1711 zx::BootDuration::from_millis(1),
1712 zx::BootDuration::from_micros(100),
1713 zx::BootDuration::from_micros(10),
1714 zx::BootDuration::from_micros(1),
1715 ],
1716 2000, zx::BootDuration::from_micros(6000),
1718 TimerDuration::new(zx::BootDuration::from_millis(1), 6) ;
1719 "Coarser exact unit wins"
1720 )]
1721 fn test_pick_setting(
1722 resolutions: Vec<zx::BootDuration>,
1723 max_ticks: u64,
1724 duration: zx::BootDuration,
1725 expected: TimerDuration,
1726 ) {
1727 let config = TimerConfig::new_from_data(MAIN_TIMER_ID as u64, &resolutions[..], max_ticks);
1728 let actual = config.pick_setting(duration);
1729
1730 assert_slack_eq(expected, actual);
1733 }
1734
1735 fn assert_slack_eq(expected: TimerDuration, actual: TimerDuration) {
1737 let slack = expected.duration() - actual.duration();
1738 assert_eq!(
1739 actual.resolution(),
1740 expected.resolution(),
1741 "\n\texpected: {} ({})\n\tactual : {} ({})\n\tslack: expected-actual={}",
1742 expected,
1743 format_duration(expected.duration()),
1744 actual,
1745 format_duration(actual.duration()),
1746 format_duration(slack)
1747 );
1748 assert_eq!(
1749 actual.ticks(),
1750 expected.ticks(),
1751 "\n\texpected: {} ({})\n\tactual : {} ({})\n\tslack: expected-actual={}",
1752 expected,
1753 format_duration(expected.duration()),
1754 actual,
1755 format_duration(actual.duration()),
1756 format_duration(slack)
1757 );
1758 }
1759
1760 #[derive(Debug)]
1761 enum FakeCmd {
1762 SetProperties {
1763 resolutions: Vec<zx::BootDuration>,
1764 max_ticks: i64,
1765 keep_alive: zx::EventPair,
1766 done: zx::Event,
1767 },
1768 Exit,
1769 }
1770
1771 use std::cell::RefCell;
1772 use std::rc::Rc;
1773
1774 fn fake_hrtimer_connection(
1780 rcv: mpsc::Receiver<FakeCmd>,
1781 ) -> (ffhh::DeviceProxy, fasync::Task<()>) {
1782 debug!("fake_hrtimer_connection: entry.");
1783 let (hrtimer, mut stream) =
1784 fidl::endpoints::create_proxy_and_stream::<ffhh::DeviceMarker>();
1785 let task = fasync::Task::local(async move {
1786 let mut rcv = rcv.fuse();
1787 let timer_properties = Rc::new(RefCell::new(None));
1788 let wake_lease = Rc::new(RefCell::new(None));
1789
1790 let timer_running = Rc::new(RefCell::new(false));
1794
1795 loop {
1796 let timer_properties = timer_properties.clone();
1797 let wake_lease = wake_lease.clone();
1798 select! {
1799 cmd = rcv.next() => {
1800 debug!("fake_hrtimer_connection: cmd: {:?}", cmd);
1801 match cmd {
1802 Some(FakeCmd::Exit) => { break; }
1803 Some(FakeCmd::SetProperties{ resolutions, max_ticks, keep_alive, done}) => {
1804 let mut timer_props = vec![];
1805 for v in 0..10 {
1806 timer_props.push(ffhh::TimerProperties {
1807 supported_resolutions: Some(
1808 resolutions.iter()
1809 .map(|d| ffhh::Resolution::Duration(d.into_nanos())).collect()),
1810 max_ticks: Some(max_ticks.try_into().unwrap()),
1811 supports_wait: Some(true),
1813 id: Some(v),
1814 ..Default::default()
1815 },
1816 );
1817 }
1818 *timer_properties.borrow_mut() = Some(timer_props);
1819 *wake_lease.borrow_mut() = Some(keep_alive);
1820 debug!("set timer properties to: {:?}", timer_properties);
1821 signal(&done);
1822 }
1823 e => {
1824 panic!("unrecognized command: {:?}", e);
1825 }
1826 }
1827 },
1829 event = stream.next() => {
1830 debug!("fake_hrtimer_connection: event: {:?}", event);
1831 if let Some(Ok(event)) = event {
1832 match event {
1833 ffhh::DeviceRequest::Start { responder, .. } => {
1834 assert!(!*timer_running.borrow(), "invariant broken: timer may not be running here");
1835 *timer_running.borrow_mut() = true;
1836 responder.send(Ok(())).expect("");
1837 }
1838 ffhh::DeviceRequest::Stop { responder, .. } => {
1839 *timer_running.borrow_mut() = false;
1840 responder.send(Ok(())).expect("");
1841 }
1842 ffhh::DeviceRequest::GetTicksLeft { responder, .. } => {
1843 responder.send(Ok(1)).expect("");
1844 }
1845 ffhh::DeviceRequest::SetEvent { responder, .. } => {
1846 responder.send(Ok(())).expect("");
1847 }
1848 ffhh::DeviceRequest::StartAndWait { id, resolution, ticks, setup_event, responder, .. } => {
1849 assert!(!*timer_running.borrow(), "invariant broken: timer may not be running here");
1850 *timer_running.borrow_mut() = true;
1851 debug!("fake_hrtimer_connection: starting timer: \"{}\", resolution: {:?}, ticks: {}", id, resolution, ticks);
1852 let ticks: i64 = ticks.try_into().unwrap();
1853 let sleep_duration = zx::BootDuration::from_nanos(ticks * match resolution {
1854 ffhh::Resolution::Duration(e) => e,
1855 _ => {
1856 error!("resolution has an unexpected value");
1857 1
1858 }
1859 });
1860 let timer_running_clone = timer_running.clone();
1861 fasync::Task::local(async move {
1862 fasync::Timer::new(sleep_duration).await;
1865 *timer_running_clone.borrow_mut() = false;
1866 responder.send(Ok(clone_handle(wake_lease.borrow().as_ref().unwrap()))).unwrap();
1867
1868 signal(&setup_event);
1871
1872 }).detach();
1873 }
1874 ffhh::DeviceRequest::StartAndWait2 { responder, .. } => {
1875 assert!(!*timer_running.borrow(), "invariant broken: timer may not be running here");
1876 *timer_running.borrow_mut() = true;
1877 responder.send(Err(ffhh::DriverError::InternalError)).expect("");
1878 }
1879 ffhh::DeviceRequest::GetProperties { responder, .. } => {
1880 if (*timer_properties).borrow().is_none() {
1881 error!("timer_properties is empty, this is not what you want!");
1882 }
1883 responder
1884 .send(ffhh::Properties {
1885 timers_properties: (*timer_properties).borrow().clone(),
1886 ..Default::default()
1887 })
1888 .expect("");
1889 }
1890 ffhh::DeviceRequest::_UnknownMethod { .. } => todo!(),
1891 }
1892 }
1893 },
1894 }
1895 }
1896 debug!("fake_hrtimer_connection: exiting");
1897 });
1898 (hrtimer, task)
1899 }
1900
1901 #[fuchsia::test]
1902 fn test_basic_timed_wait() {
1903 let deadline = zx::BootInstant::from_nanos(100);
1904 let test_duration = zx::MonotonicDuration::from_nanos(110);
1905 run_in_fake_time_and_test_context(test_duration, |wake_proxy, _| async move {
1906 let keep_alive = zx::Event::create();
1907
1908 wake_proxy
1909 .set_and_wait(deadline.into(), keep_alive, "Hello".into())
1910 .await
1911 .unwrap()
1912 .unwrap();
1913
1914 assert_gt!(fasync::BootInstant::now().into_nanos(), deadline.into_nanos());
1915 });
1916 }
1917
1918 #[test_case(
1919 zx::BootInstant::from_nanos(100),
1920 zx::BootInstant::from_nanos(200),
1921 zx::MonotonicDuration::from_nanos(250) ;
1922 "Two timers: one at 100 and another at 200 ns"
1923 )]
1924 #[test_case(
1925 zx::BootInstant::from_nanos(100),
1926 zx::BootInstant::from_nanos(100),
1927 zx::MonotonicDuration::from_nanos(104) ;
1929 "Two timers at the same deadline."
1930 )]
1931 #[test_case(
1932 zx::BootInstant::from_nanos(-1),
1933 zx::BootInstant::from_nanos(-1),
1934 zx::MonotonicDuration::from_nanos(30) ;
1935 "Two timers expire immediately."
1936 )]
1937 #[fuchsia::test]
1938 fn test_timed_wait_two_timers_params(
1939 first_deadline: zx::BootInstant,
1941 second_deadline: zx::BootInstant,
1943 duration: zx::MonotonicDuration,
1945 ) {
1946 run_in_fake_time_and_test_context(duration, |wake_proxy, _| async move {
1947 let lease1 = zx::Event::create();
1948 let fut1 = wake_proxy.set_and_wait(first_deadline.into(), lease1, "Hello1".into());
1949
1950 let lease2 = zx::Event::create();
1951 let fut2 = wake_proxy.set_and_wait(second_deadline.into(), lease2, "Hello2".into());
1952
1953 let (result1, result2) = futures::join!(fut1, fut2);
1954
1955 result1.unwrap().unwrap();
1956 result2.unwrap().unwrap();
1957
1958 assert_gt!(fasync::BootInstant::now().into_nanos(), first_deadline.into_nanos());
1959 assert_gt!(fasync::BootInstant::now().into_nanos(), second_deadline.into_nanos());
1960 });
1961 }
1962
1963 #[test_case(
1964 zx::BootInstant::from_nanos(100),
1965 zx::BootInstant::from_nanos(200),
1966 zx::MonotonicDuration::from_nanos(250) ;
1967 "Reschedule with push-out"
1968 )]
1969 #[test_case(
1970 zx::BootInstant::from_nanos(100),
1971 zx::BootInstant::from_nanos(100),
1972 zx::MonotonicDuration::from_nanos(104) ;
1974 "Reschedule with same deadline"
1975 )]
1976 #[test_case(
1977 zx::BootInstant::from_nanos(200),
1978 zx::BootInstant::from_nanos(100),
1979 zx::MonotonicDuration::from_nanos(240) ;
1981 "Pull in"
1982 )]
1983 #[fuchsia::test]
1984 fn test_timed_wait_same_timer(
1985 first_deadline: zx::BootInstant,
1987 second_deadline: zx::BootInstant,
1989 duration: zx::MonotonicDuration,
1991 ) {
1992 run_in_fake_time_and_test_context(duration, |wake_proxy, _| async move {
1993 let lease1 = zx::Event::create();
1994
1995 wake_proxy
1996 .set_and_wait(first_deadline.into(), lease1, "Hello".into())
1997 .await
1998 .unwrap()
1999 .unwrap();
2000 let lease2 = zx::Event::create();
2001 wake_proxy
2002 .set_and_wait(second_deadline.into(), lease2, "Hello2".into())
2003 .await
2004 .unwrap()
2005 .unwrap();
2006 });
2007 }
2008
2009 #[fuchsia::test]
2012 fn test_reschedule_pull_in() {
2013 const LONG_DEADLINE_NANOS: i64 = 200;
2014 const SHORT_DEADLINE_NANOS: i64 = 100;
2015 const ALARM_ID: &str = "Hello";
2016 run_in_fake_time_and_test_context(
2017 zx::MonotonicDuration::from_nanos(LONG_DEADLINE_NANOS + 50),
2018 |wake_proxy, _| async move {
2019 let wake_proxy = Rc::new(RefCell::new(wake_proxy));
2020
2021 let keep_alive = zx::Event::create();
2022
2023 let (mut sync_send, mut sync_recv) = mpsc::channel(1);
2024
2025 let wake_proxy_clone = wake_proxy.clone();
2028 let long_deadline_fut = async move {
2029 let wake_fut = wake_proxy_clone.borrow().set_and_wait(
2030 zx::BootInstant::from_nanos(LONG_DEADLINE_NANOS).into(),
2031 keep_alive,
2032 ALARM_ID.into(),
2033 );
2034 sync_send.send(()).await.unwrap();
2036
2037 wake_fut.await.unwrap().unwrap();
2039 };
2040
2041 let short_deadline_fut = async move {
2045 let _ = sync_recv.next().await;
2047
2048 let keep_alive2 = zx::Event::create();
2049 let _ = wake_proxy
2050 .borrow()
2051 .set_and_wait(
2052 zx::BootInstant::from_nanos(SHORT_DEADLINE_NANOS).into(),
2053 keep_alive2,
2054 ALARM_ID.into(),
2055 )
2056 .await
2057 .unwrap()
2058 .unwrap();
2059
2060 assert_gt!(fasync::BootInstant::now().into_nanos(), SHORT_DEADLINE_NANOS);
2062 assert_lt!(fasync::BootInstant::now().into_nanos(), LONG_DEADLINE_NANOS);
2063 };
2064 futures::join!(short_deadline_fut, long_deadline_fut);
2065 },
2066 );
2067 }
2068
2069 #[fuchsia::test]
2072 fn test_reschedule_push_out() {
2073 const LONG_DEADLINE_NANOS: i64 = 200;
2074 const SHORT_DEADLINE_NANOS: i64 = 100;
2075 const ALARM_ID: &str = "Hello";
2076 run_in_fake_time_and_test_context(
2077 zx::MonotonicDuration::from_nanos(LONG_DEADLINE_NANOS + 50),
2078 |wake_proxy, inspector| async move {
2079 let wake_proxy = Rc::new(RefCell::new(wake_proxy));
2080
2081 let keep_alive = zx::Event::create();
2082
2083 let (mut sync_send, mut sync_recv) = mpsc::channel(1);
2084
2085 let wake_proxy_clone = wake_proxy.clone();
2088 let short_deadline_fut = async move {
2089 let wake_fut = wake_proxy_clone.borrow().set_and_wait(
2090 zx::BootInstant::from_nanos(SHORT_DEADLINE_NANOS).into(),
2091 keep_alive,
2092 ALARM_ID.into(),
2093 );
2094 sync_send.send(()).await.unwrap();
2096
2097 let result = wake_fut.await.unwrap();
2099 assert_eq!(
2100 result,
2101 Err(fta::WakeError::Dropped),
2102 "expected wake alarm to be dropped"
2103 );
2104 assert_gt!(fasync::BootInstant::now().into_nanos(), SHORT_DEADLINE_NANOS);
2105 };
2106
2107 let long_deadline_fut = async move {
2111 let _ = sync_recv.next().await;
2113
2114 let keep_alive2 = zx::Event::create();
2115 let _ = wake_proxy
2116 .borrow()
2117 .set_and_wait(
2118 zx::BootInstant::from_nanos(LONG_DEADLINE_NANOS).into(),
2119 keep_alive2,
2120 ALARM_ID.into(),
2121 )
2122 .await
2123 .unwrap()
2124 .unwrap();
2125
2126 assert_gt!(fasync::BootInstant::now().into_nanos(), LONG_DEADLINE_NANOS);
2128 };
2129 futures::join!(long_deadline_fut, short_deadline_fut);
2130
2131 assert_data_tree!(inspector, root: {
2134 test: {
2135 hardware: {
2136 current_deadline: "(none)",
2138 remaining_until_alarm: "(none)",
2139 },
2140 now_formatted: "247ns (247)",
2141 now_ns: 247i64,
2142 pending_timers: "\n\t",
2143 pending_timers_count: 0u64,
2144 requested_deadlines_ns: AnyProperty,
2145 },
2146 });
2147 },
2148 );
2149 }
2150}