1mod emu;
29
30use crate::emu::EmulationTimerOps;
31use anyhow::{anyhow, Result};
32use async_trait::async_trait;
33use fidl::encoding::ProxyChannelBox;
34use fidl::endpoints::RequestStream;
35use fidl::HandleBased;
36use fuchsia_inspect::{HistogramProperty, Property};
37use futures::channel::mpsc;
38use futures::sink::SinkExt;
39use futures::StreamExt;
40use log::{debug, error, warn};
41use scopeguard::defer;
42use std::cell::RefCell;
43use std::cmp;
44use std::collections::{BTreeMap, BinaryHeap, HashMap};
45use std::rc::Rc;
46use std::sync::LazyLock;
47use time_pretty::{format_duration, format_timer, MSEC_IN_NANOS};
48use zx::AsHandleRef;
49use {
50 fidl_fuchsia_hardware_hrtimer as ffhh, fidl_fuchsia_time_alarms as fta,
51 fuchsia_async as fasync, fuchsia_inspect as finspect, fuchsia_trace as trace,
52};
53
54static I64_MAX_AS_U64: LazyLock<u64> = LazyLock::new(|| i64::MAX.try_into().expect("infallible"));
55static I32_MAX_AS_U64: LazyLock<u64> = LazyLock::new(|| i32::MAX.try_into().expect("infallible"));
56
57static MAX_USEFUL_TICKS: LazyLock<u64> = LazyLock::new(|| *I32_MAX_AS_U64);
59
60const MAIN_TIMER_ID: usize = 6;
63
64const TEMPORARY_STARNIX_TIMER_ID: &str = "starnix-hrtimer";
69static TEMPORARY_STARNIX_CID: LazyLock<zx::Event> = LazyLock::new(|| zx::Event::create());
70
71fn is_deadline_changed(
74 before: Option<fasync::BootInstant>,
75 after: Option<fasync::BootInstant>,
76) -> bool {
77 match (before, after) {
78 (None, None) => false,
79 (None, Some(_)) | (Some(_), None) => true,
80 (Some(before), Some(after)) => before != after,
81 }
82}
83
84#[derive(Debug)]
86pub(crate) enum TimerOpsError {
87 Driver(ffhh::DriverError),
89 Fidl(fidl::Error),
91}
92
93trait SawResponseFut: std::future::Future<Output = Result<zx::EventPair, TimerOpsError>> {
94 }
96
97#[async_trait(?Send)]
99pub(crate) trait TimerOps {
100 async fn stop(&self, id: u64);
102
103 async fn get_timer_properties(&self) -> TimerConfig;
106
107 fn start_and_wait(
112 &self,
113 id: u64,
114 resolution: &ffhh::Resolution,
115 ticks: u64,
116 setup_event: zx::Event,
117 ) -> std::pin::Pin<Box<dyn SawResponseFut>>;
118}
119
120struct HardwareTimerOps {
122 proxy: ffhh::DeviceProxy,
123}
124
125impl HardwareTimerOps {
126 fn new(proxy: ffhh::DeviceProxy) -> Box<Self> {
127 Box::new(Self { proxy })
128 }
129}
130
131#[async_trait(?Send)]
132impl TimerOps for HardwareTimerOps {
133 async fn stop(&self, id: u64) {
134 let _ = self
135 .proxy
136 .stop(id)
137 .await
138 .map(|result| {
139 let _ = result.map_err(|e| warn!("stop_hrtimer: driver error: {:?}", e));
140 })
141 .map_err(|e| warn!("stop_hrtimer: could not stop prior timer: {}", e));
142 }
143
144 async fn get_timer_properties(&self) -> TimerConfig {
145 match self.proxy.get_properties().await {
146 Ok(p) => {
147 let timers_properties = &p.timers_properties.expect("timers_properties must exist");
148 debug!("get_timer_properties: got: {:?}", timers_properties);
149
150 let timer_index = if timers_properties.len() > MAIN_TIMER_ID {
152 MAIN_TIMER_ID
155 } else if timers_properties.len() > 0 {
156 0
160 } else {
161 return TimerConfig::new_empty();
163 };
164 let main_timer_properties = &timers_properties[timer_index];
165 debug!("alarms: main_timer_properties: {:?}", main_timer_properties);
166 let max_ticks: u64 = std::cmp::min(
168 main_timer_properties.max_ticks.unwrap_or(*MAX_USEFUL_TICKS),
169 *MAX_USEFUL_TICKS,
170 );
171 let resolutions = &main_timer_properties
172 .supported_resolutions
173 .as_ref()
174 .expect("supported_resolutions is populated")
175 .iter()
176 .last() .map(|r| match *r {
178 ffhh::Resolution::Duration(d) => d,
179 _ => {
180 error!(
181 "get_timer_properties: Unknown resolution type, returning millisecond."
182 );
183 MSEC_IN_NANOS
184 }
185 })
186 .map(|d| zx::BootDuration::from_nanos(d))
187 .into_iter() .collect::<Vec<_>>();
189 let timer_id = main_timer_properties.id.expect("timer ID is always present");
190 TimerConfig::new_from_data(timer_id, resolutions, max_ticks)
191 }
192 Err(e) => {
193 error!("could not get timer properties: {:?}", e);
194 TimerConfig::new_empty()
195 }
196 }
197 }
198
199 fn start_and_wait(
200 &self,
201 id: u64,
202 resolution: &ffhh::Resolution,
203 ticks: u64,
204 setup_event: zx::Event,
205 ) -> std::pin::Pin<Box<dyn SawResponseFut>> {
206 let inner = self.proxy.start_and_wait(id, resolution, ticks, setup_event);
207 Box::pin(HwResponseFut { pinner: Box::pin(inner) })
208 }
209}
210
211struct HwResponseFut {
214 pinner: std::pin::Pin<
215 Box<
216 fidl::client::QueryResponseFut<
217 ffhh::DeviceStartAndWaitResult,
218 fidl::encoding::DefaultFuchsiaResourceDialect,
219 >,
220 >,
221 >,
222}
223
224use std::task::Poll;
225impl SawResponseFut for HwResponseFut {}
226impl std::future::Future for HwResponseFut {
227 type Output = Result<zx::EventPair, TimerOpsError>;
228 fn poll(
229 mut self: std::pin::Pin<&mut Self>,
230 cx: &mut std::task::Context<'_>,
231 ) -> std::task::Poll<Self::Output> {
232 let inner_poll = self.pinner.as_mut().poll(cx);
233 match inner_poll {
234 Poll::Ready(result) => Poll::Ready(match result {
235 Ok(Ok(keep_alive)) => Ok(keep_alive),
236 Ok(Err(e)) => Err(TimerOpsError::Driver(e)),
237 Err(e) => Err(TimerOpsError::Fidl(e)),
238 }),
239 Poll::Pending => Poll::Pending,
240 }
241 }
242}
243
244async fn stop_hrtimer(hrtimer: &Box<dyn TimerOps>, timer_config: &TimerConfig) {
246 trace::duration!(c"alarms", c"hrtimer:stop", "id" => timer_config.id);
247 debug!("stop_hrtimer: stopping hardware timer: {}", timer_config.id);
248 hrtimer.stop(timer_config.id).await;
249 debug!("stop_hrtimer: stopped hardware timer: {}", timer_config.id);
250}
251
252const CHANNEL_SIZE: usize = 100;
254
255#[derive(Debug)]
257enum Cmd {
258 Start {
260 cid: zx::Koid,
262 deadline: fasync::BootInstant,
264 mode: fta::SetAndWaitMode,
266 alarm_id: String,
268 responder: Rc<RefCell<Option<fta::WakeSetAndWaitResponder>>>,
276 },
277 StopById {
278 done: zx::Event,
279 timer_id: TimerId,
280 },
281 Alarm {
282 expired_deadline: fasync::BootInstant,
283 keep_alive: fidl::EventPair,
284 },
285 AlarmFidlError {
286 expired_deadline: fasync::BootInstant,
287 error: fidl::Error,
288 },
289 AlarmDriverError {
290 expired_deadline: fasync::BootInstant,
291 error: ffhh::DriverError,
292 },
293}
294
295impl std::fmt::Display for Cmd {
296 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
297 match self {
298 Cmd::Start { cid, deadline, alarm_id, .. } => {
299 write!(
300 f,
301 "Start[alarm_id=\"{}\", cid={:?}, deadline={}]",
302 alarm_id,
303 cid,
304 format_timer((*deadline).into())
305 )
306 }
307 Cmd::Alarm { expired_deadline, .. } => {
308 write!(f, "Alarm[deadline={}]", format_timer((*expired_deadline).into()))
309 }
310 Cmd::AlarmFidlError { expired_deadline, error } => {
311 write!(
312 f,
313 "FIDLError[deadline={}, err={}, NO_WAKE_LEASE!]",
314 format_timer((*expired_deadline).into()),
315 error
316 )
317 }
318 Cmd::AlarmDriverError { expired_deadline, error } => {
319 write!(
320 f,
321 "DriverError[deadline={}, err={:?}, NO_WAKE_LEASE!]",
322 format_timer((*expired_deadline).into()),
323 error
324 )
325 }
326 Cmd::StopById { timer_id, done: _ } => {
327 write!(f, "StopById[timerId={}]", timer_id,)
328 }
329 }
330 }
331}
332
333pub fn get_stream_koid(stream: fta::WakeRequestStream) -> (zx::Koid, fta::WakeRequestStream) {
340 let (inner, is_terminated) = stream.into_inner();
341 let koid = inner.channel().as_channel().get_koid().expect("infallible");
342 let stream = fta::WakeRequestStream::from_inner(inner, is_terminated);
343 (koid, stream)
344}
345
346pub async fn serve(timer_loop: Rc<Loop>, requests: fta::WakeRequestStream) {
348 fasync::Task::local(async move {
350 let timer_loop = timer_loop.clone();
351 let timer_loop_send = || timer_loop.get_sender();
352 let (cid, mut requests) = get_stream_koid(requests);
353 let mut request_count = 0;
354 debug!("alarms::serve: opened connection: {:?}", cid);
355 while let Some(maybe_request) = requests.next().await {
356 request_count += 1;
357 debug!("alarms::serve: cid: {:?} incoming request: {}", cid, request_count);
358 match maybe_request {
359 Ok(request) => {
360 handle_request(cid, timer_loop_send(), request).await;
362 }
363 Err(e) => {
364 warn!("alarms::serve: error in request: {:?}", e);
365 }
366 }
367 debug!("alarms::serve: cid: {:?} done request: {}", cid, request_count);
368 }
369 warn!("alarms::serve: CLOSED CONNECTION: cid: {:?}", cid);
372 })
373 .detach();
374}
375
376fn compute_cid(cid: zx::Koid, alarm_id: &str) -> zx::Koid {
380 if alarm_id == TEMPORARY_STARNIX_TIMER_ID {
381 TEMPORARY_STARNIX_CID.as_handle_ref().get_koid().expect("infallible")
384 } else {
385 cid
386 }
387}
388
389async fn handle_cancel(alarm_id: String, cid: zx::Koid, cmd: &mut mpsc::Sender<Cmd>) {
390 let done = zx::Event::create();
391 let cid = compute_cid(cid, &alarm_id);
392 let timer_id = TimerId { alarm_id: alarm_id.clone(), cid };
393 if let Err(e) = cmd.send(Cmd::StopById { timer_id, done: clone_handle(&done) }).await {
394 warn!("handle_request: error while trying to cancel: {}: {:?}", alarm_id, e);
395 }
396 wait_signaled(&done).await;
397}
398
399async fn handle_request(cid: zx::Koid, mut cmd: mpsc::Sender<Cmd>, request: fta::WakeRequest) {
407 match request {
408 fta::WakeRequest::SetAndWait { deadline, mode, alarm_id, responder } => {
409 let responder = Rc::new(RefCell::new(Some(responder)));
419 let cid = compute_cid(cid, &alarm_id);
420
421 debug!(
423 "handle_request: scheduling alarm_id: \"{}\"\n\tcid: {:?}\n\tdeadline: {}",
424 alarm_id,
425 cid,
426 format_timer(deadline.into())
427 );
428 if let Err(e) = cmd
430 .send(Cmd::Start {
431 cid,
432 deadline: deadline.into(),
433 mode,
434 alarm_id: alarm_id.clone(),
435 responder: responder.clone(),
436 })
437 .await
438 {
439 warn!("handle_request: error while trying to schedule `{}`: {:?}", alarm_id, e);
440 responder
441 .borrow_mut()
442 .take()
443 .expect("always present if call fails")
444 .send(Err(fta::WakeError::Internal))
445 .unwrap();
446 }
447 }
448 fta::WakeRequest::Cancel { alarm_id, .. } => {
449 handle_cancel(alarm_id, cid, &mut cmd).await;
452 }
453 fta::WakeRequest::_UnknownMethod { .. } => {}
454 };
455}
456
457pub struct Loop {
461 _task: fasync::Task<()>,
463 snd_cloneable: mpsc::Sender<Cmd>,
466}
467
468impl Loop {
469 pub fn new(device_proxy: ffhh::DeviceProxy, inspect: finspect::Node) -> Self {
473 let hw_device_timer_ops = HardwareTimerOps::new(device_proxy);
474 Loop::new_internal(hw_device_timer_ops, inspect)
475 }
476
477 pub fn new_emulated(inspect: finspect::Node) -> Self {
479 let timer_ops = Box::new(EmulationTimerOps::new());
480 Loop::new_internal(timer_ops, inspect)
481 }
482
483 fn new_internal(timer_ops: Box<dyn TimerOps>, inspect: finspect::Node) -> Self {
484 let (snd, rcv) = mpsc::channel(CHANNEL_SIZE);
485 let snd_clone = snd.clone();
486 let _task = fasync::Task::local(async move {
487 wake_timer_loop(snd_clone, rcv, timer_ops, inspect).await
488 });
489 Self { _task, snd_cloneable: snd }
490 }
491
492 fn get_sender(&self) -> mpsc::Sender<Cmd> {
495 self.snd_cloneable.clone()
496 }
497}
498
499#[derive(Debug)]
501struct TimerNode {
502 deadline: fasync::BootInstant,
504 alarm_id: String,
506 cid: zx::Koid,
509 responder: Option<fta::WakeSetAndWaitResponder>,
512}
513
514impl TimerNode {
515 fn new(
516 deadline: fasync::BootInstant,
517 alarm_id: String,
518 cid: zx::Koid,
519 responder: fta::WakeSetAndWaitResponder,
520 ) -> Self {
521 Self { deadline, alarm_id, cid, responder: Some(responder) }
522 }
523
524 fn get_alarm_id(&self) -> &str {
525 &self.alarm_id[..]
526 }
527
528 fn get_cid(&self) -> &zx::Koid {
529 &self.cid
530 }
531
532 fn get_id(&self) -> TimerId {
533 TimerId { alarm_id: self.alarm_id.clone(), cid: self.cid.clone() }
534 }
535
536 fn get_deadline(&self) -> &fasync::BootInstant {
537 &self.deadline
538 }
539
540 fn take_responder(&mut self) -> Option<fta::WakeSetAndWaitResponder> {
541 self.responder.take()
542 }
543}
544
545impl Drop for TimerNode {
546 fn drop(&mut self) {
549 let responder = self.take_responder();
550 responder.map(|r| {
551 r.send(Err(fta::WakeError::Dropped))
555 .map_err(|e| error!("could not drop responder: {:?}", e))
556 });
557 }
558}
559
560impl std::cmp::Eq for TimerNode {}
563
564impl std::cmp::PartialEq for TimerNode {
565 fn eq(&self, other: &Self) -> bool {
566 self.deadline == other.deadline && self.alarm_id == other.alarm_id && self.cid == other.cid
567 }
568}
569
570impl std::cmp::PartialOrd for TimerNode {
571 fn partial_cmp(&self, other: &Self) -> Option<cmp::Ordering> {
574 Some(self.cmp(other))
575 }
576}
577
578impl Ord for TimerNode {
579 fn cmp(&self, other: &Self) -> std::cmp::Ordering {
583 let ordering = other.deadline.cmp(&self.deadline);
584 if ordering == std::cmp::Ordering::Equal {
585 let ordering = self.alarm_id.cmp(&self.alarm_id);
586 if ordering == std::cmp::Ordering::Equal {
587 self.cid.cmp(&other.cid)
588 } else {
589 ordering
590 }
591 } else {
592 ordering
593 }
594 }
595}
596
597#[derive(Debug, PartialEq, Eq, Hash)]
599struct TimerId {
600 alarm_id: String,
602 cid: zx::Koid,
604}
605
606impl std::fmt::Display for TimerId {
607 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
608 write!(f, "TimerId[alarm_id:{},cid:{:?}]", self.alarm_id, self.cid)
609 }
610}
611
612struct Timers {
618 timers: BinaryHeap<TimerNode>,
619 deadline_by_id: HashMap<TimerId, fasync::BootInstant>,
620}
621
622impl std::fmt::Display for Timers {
623 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
624 let now = fasync::BootInstant::now();
625 let sorted = self
626 .timers
627 .iter()
628 .map(|n| (n.deadline, n.alarm_id.clone()))
629 .collect::<BTreeMap<_, _>>()
630 .into_iter()
631 .map(|(k, v)| {
632 let remaining = k - now;
633 format!(
634 "Timeout: {} => timer_id: {}, remaining: {}",
635 format_timer(k.into()),
636 v,
637 format_duration(remaining.into())
638 )
639 })
640 .collect::<Vec<_>>();
641 let joined = sorted.join("\n\t");
642 write!(f, "\n\t{}", joined)
643 }
644}
645
646impl Timers {
647 fn new() -> Self {
649 Self { timers: BinaryHeap::new(), deadline_by_id: HashMap::new() }
650 }
651
652 fn push(&mut self, n: TimerNode) {
658 let new_id = n.get_id();
659 if let Some(deadline) = self.deadline_by_id.get(&new_id) {
660 if n.deadline == *deadline {
662 return;
663 }
664 self.deadline_by_id.insert(new_id, n.deadline.clone());
666 self.timers.retain(|t| t.get_id() != n.get_id());
667 self.timers.push(n);
668 } else {
669 self.deadline_by_id.insert(new_id, n.deadline);
671 self.timers.push(n);
672 }
673 }
674
675 fn peek(&self) -> Option<&TimerNode> {
677 self.timers.peek()
678 }
679
680 fn peek_deadline(&self) -> Option<fasync::BootInstant> {
682 self.peek().map(|t| t.deadline)
683 }
684
685 fn peek_id(&self) -> Option<TimerId> {
686 self.peek().map(|t| TimerId { alarm_id: t.alarm_id.clone(), cid: t.cid })
687 }
688
689 fn expired(now: fasync::BootInstant, deadline: fasync::BootInstant) -> bool {
693 deadline <= now
694 }
695
696 fn is_empty(&self) -> bool {
698 let empty1 = self.timers.is_empty();
699 let empty2 = self.deadline_by_id.is_empty();
700 assert!(empty1 == empty2, "broken invariant: empty1: {} empty2:{}", empty1, empty2);
701 empty1
702 }
703
704 fn maybe_expire_earliest(&mut self, now: fasync::BootInstant) -> Option<TimerNode> {
715 self.peek_deadline()
716 .map(|d| {
717 if Timers::expired(now, d) {
718 self.timers.pop().map(|e| {
719 self.deadline_by_id.remove(&e.get_id());
720 e
721 })
722 } else {
723 None
724 }
725 })
726 .flatten()
727 }
728
729 fn remove_by_id(&mut self, timer_id: &TimerId) -> Option<TimerNode> {
732 let ret = if let Some(t) = self.peek_id() {
733 if t == *timer_id {
734 self.timers.pop()
735 } else {
736 None
737 }
738 } else {
739 None
740 };
741
742 self.timers.retain(|t| t.alarm_id != timer_id.alarm_id || t.cid != timer_id.cid);
743 self.deadline_by_id.remove(timer_id);
744 ret
745 }
746
747 fn timer_count(&self) -> usize {
749 let count1 = self.timers.len();
750 let count2 = self.deadline_by_id.len();
751 assert!(count1 == count2, "broken invariant: count1: {}, count2: {}", count1, count2);
752 count1
753 }
754}
755
756pub(crate) fn clone_handle<H: HandleBased>(handle: &H) -> H {
758 handle.duplicate_handle(zx::Rights::SAME_RIGHTS).expect("infallible")
759}
760
761async fn wait_signaled<H: HandleBased>(handle: &H) {
762 fasync::OnSignals::new(handle, zx::Signals::EVENT_SIGNALED).await.expect("infallible");
763}
764
765pub(crate) fn signal<H: HandleBased>(handle: &H) {
766 handle.signal_handle(zx::Signals::NONE, zx::Signals::EVENT_SIGNALED).expect("infallible");
767}
768
769#[derive(Debug, Clone, Copy)]
777struct TimerDuration {
778 resolution: zx::BootDuration,
780 ticks: u64,
783}
784
785impl Eq for TimerDuration {}
788
789impl std::cmp::PartialOrd for TimerDuration {
790 fn partial_cmp(&self, other: &TimerDuration) -> Option<std::cmp::Ordering> {
791 Some(self.cmp(other))
792 }
793}
794
795impl std::cmp::PartialEq for TimerDuration {
796 fn eq(&self, other: &Self) -> bool {
797 self.cmp(other) == std::cmp::Ordering::Equal
798 }
799}
800
801impl std::cmp::Ord for TimerDuration {
802 fn cmp(&self, other: &TimerDuration) -> std::cmp::Ordering {
805 let self_ticks_128: i128 = self.ticks as i128;
806 let self_resolution: i128 = self.resolution_as_nanos() as i128;
807 let self_nanos = self_resolution * self_ticks_128;
808
809 let other_ticks_128: i128 = other.ticks as i128;
810 let other_resolution: i128 = other.resolution_as_nanos() as i128;
811 let other_nanos = other_resolution * other_ticks_128;
812
813 self_nanos.cmp(&other_nanos)
814 }
815}
816
817impl std::fmt::Display for TimerDuration {
818 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
822 let ticks = self.ticks;
823 let resolution = self.resolution();
824 write!(f, "{}x{}", ticks, format_duration(resolution),)
826 }
827}
828
829impl TimerDuration {
830 fn max() -> Self {
832 TimerDuration::new(zx::BootDuration::from_nanos(1), *I64_MAX_AS_U64)
833 }
834
835 fn zero() -> Self {
837 TimerDuration::new(zx::BootDuration::from_nanos(1), 0)
838 }
839
840 fn new(resolution: zx::BootDuration, ticks: u64) -> Self {
842 Self { resolution, ticks }
843 }
844
845 fn new_with_resolution(res_source: &TimerDuration, ticks: u64) -> Self {
848 Self::new(res_source.resolution, ticks)
849 }
850
851 fn duration(&self) -> zx::BootDuration {
856 let duration_as_nanos = self.resolution_as_nanos() * self.ticks;
857 let clamp_duration = std::cmp::min(*I32_MAX_AS_U64, duration_as_nanos);
858 zx::BootDuration::from_nanos(clamp_duration.try_into().expect("result was clamped"))
859 }
860
861 fn resolution(&self) -> zx::BootDuration {
863 self.resolution
864 }
865
866 fn resolution_as_nanos(&self) -> u64 {
867 self.resolution().into_nanos().try_into().expect("resolution is never negative")
868 }
869
870 fn ticks(&self) -> u64 {
872 self.ticks
873 }
874}
875
876impl From<zx::BootDuration> for TimerDuration {
877 fn from(d: zx::BootDuration) -> TimerDuration {
878 let nanos = d.into_nanos();
879 assert!(nanos >= 0);
880 let nanos_u64 = nanos.try_into().expect("guarded by assert");
881 TimerDuration::new(zx::BootDuration::from_nanos(1), nanos_u64)
882 }
883}
884
885impl std::ops::Div for TimerDuration {
886 type Output = u64;
887 fn div(self, rhs: Self) -> Self::Output {
888 let self_nanos = self.resolution_as_nanos() * self.ticks;
889 let rhs_nanos = rhs.resolution_as_nanos() * rhs.ticks;
890 self_nanos / rhs_nanos
891 }
892}
893
894impl std::ops::Mul<u64> for TimerDuration {
895 type Output = Self;
896 fn mul(self, rhs: u64) -> Self::Output {
897 Self::new(self.resolution, self.ticks * rhs)
898 }
899}
900
901#[derive(Debug)]
903pub(crate) struct TimerConfig {
904 resolutions: Vec<zx::BootDuration>,
908 max_ticks: u64,
913 id: u64,
915}
916
917impl TimerConfig {
918 fn new_from_data(timer_id: u64, resolutions: &[zx::BootDuration], max_ticks: u64) -> Self {
921 debug!(
922 "TimerConfig: resolutions: {:?}, max_ticks: {}, timer_id: {}",
923 resolutions.iter().map(|r| format_duration(*r)).collect::<Vec<_>>(),
924 max_ticks,
925 timer_id
926 );
927 let resolutions = resolutions.iter().map(|d| *d).collect::<Vec<zx::BootDuration>>();
928 TimerConfig { resolutions, max_ticks, id: timer_id }
929 }
930
931 fn new_empty() -> Self {
932 error!("TimerConfig::new_empty() called, this is not OK.");
933 TimerConfig { resolutions: vec![], max_ticks: 0, id: 0 }
934 }
935
936 fn pick_setting(&self, duration: zx::BootDuration) -> TimerDuration {
946 let mut best_positive_slack = TimerDuration::zero();
953 let mut best_negative_slack = TimerDuration::max();
954
955 if self.max_ticks == 0 {
956 return TimerDuration::new(zx::BootDuration::from_millis(1), 0);
957 }
958 let duration_slack: TimerDuration = duration.into();
959
960 for res1 in self.resolutions.iter() {
961 let smallest_unit = TimerDuration::new(*res1, 1);
962 let max_tick_at_res = TimerDuration::new(*res1, self.max_ticks);
963
964 let smallest_slack_larger_than_duration = smallest_unit > duration_slack;
965 let largest_slack_smaller_than_duration = max_tick_at_res < duration_slack;
966
967 if smallest_slack_larger_than_duration {
968 if duration_slack == TimerDuration::zero() {
969 best_negative_slack = TimerDuration::zero();
970 } else if smallest_unit < best_negative_slack {
971 best_negative_slack = smallest_unit;
972 }
973 }
974 if largest_slack_smaller_than_duration {
975 if max_tick_at_res > best_positive_slack
976 || best_positive_slack == TimerDuration::zero()
977 {
978 best_positive_slack = max_tick_at_res;
979 }
980 }
981
982 if !smallest_slack_larger_than_duration && !largest_slack_smaller_than_duration {
984 let q = duration_slack / smallest_unit;
987 let d = smallest_unit * q;
988 if d == duration_slack {
989 return d;
991 } else {
992 if d > best_positive_slack {
994 best_positive_slack = TimerDuration::new_with_resolution(&smallest_unit, q);
995 }
996 let d_plus = TimerDuration::new_with_resolution(&smallest_unit, q + 1);
997 if d_plus < best_negative_slack {
998 best_negative_slack = d_plus;
999 }
1000 }
1001 }
1002 }
1003
1004 let p_slack = duration - best_positive_slack.duration();
1005 let n_slack = best_negative_slack.duration() - duration;
1006
1007 let ret = if p_slack < n_slack && best_positive_slack.duration().into_nanos() > 0 {
1012 best_positive_slack
1013 } else {
1014 best_negative_slack
1015 };
1016 debug!("TimerConfig: picked slack: {} for duration: {}", ret, format_duration(duration));
1017 assert!(
1018 ret.duration().into_nanos() >= 0,
1019 "ret: {}, p_slack: {}, n_slack: {}, orig.duration: {}\n\tbest_p_slack: {}\n\tbest_n_slack: {}\n\ttarget: {}\n\t 1: {} 2: {:?}, 3: {:?}",
1020 ret,
1021 format_duration(p_slack),
1022 format_duration(n_slack),
1023 format_duration(duration),
1024 best_positive_slack,
1025 best_negative_slack,
1026 duration_slack,
1027 p_slack != zx::BootDuration::ZERO,
1028 p_slack,
1029 zx::BootDuration::ZERO,
1030 );
1031 ret
1032 }
1033}
1034
1035async fn get_timer_properties(hrtimer: &Box<dyn TimerOps>) -> TimerConfig {
1036 debug!("get_timer_properties: requesting timer properties.");
1037 hrtimer.get_timer_properties().await
1038}
1039
1040struct TimerState {
1042 task: fasync::Task<()>,
1044 deadline: fasync::BootInstant,
1046}
1047
1048async fn wake_timer_loop(
1057 snd: mpsc::Sender<Cmd>,
1058 mut cmds: mpsc::Receiver<Cmd>,
1059 timer_proxy: Box<dyn TimerOps>,
1060 inspect: finspect::Node,
1061) {
1062 debug!("wake_timer_loop: started");
1063
1064 let mut timers = Timers::new();
1065 let timer_config = get_timer_properties(&timer_proxy).await;
1066
1067 #[allow(clippy::collection_is_never_read)]
1070 let mut hrtimer_status: Option<TimerState> = None;
1071
1072 let now_prop = inspect.create_int("now_ns", 0);
1079 let now_formatted_prop = inspect.create_string("now_formatted", "");
1080 let pending_timers_count_prop = inspect.create_uint("pending_timers_count", 0);
1081 let pending_timers_prop = inspect.create_string("pending_timers", "");
1082 let deadline_histogram_prop = inspect.create_int_exponential_histogram(
1083 "requested_deadlines_ns",
1084 finspect::ExponentialHistogramParams {
1085 floor: 0,
1086 initial_step: zx::BootDuration::from_micros(1).into_nanos(),
1087 step_multiplier: 10,
1089 buckets: 16,
1090 },
1091 );
1092 let hw_node = inspect.create_child("hardware");
1094 let current_hw_deadline_prop = hw_node.create_string("current_deadline", "");
1095 let remaining_until_alarm_prop = hw_node.create_string("remaining_until_alarm", "");
1096
1097 while let Some(cmd) = cmds.next().await {
1098 trace::duration!(c"alarms", c"Cmd");
1099 let now = fasync::BootInstant::now();
1101 now_prop.set(now.into_nanos());
1102 trace::instant!(c"alarms", c"wake_timer_loop", trace::Scope::Process, "now" => now.into_nanos());
1103 match cmd {
1104 Cmd::Start { cid, deadline, mode, alarm_id, responder } => {
1105 trace::duration!(c"alarms", c"Cmd::Start");
1106 let responder = responder.borrow_mut().take().expect("responder is always present");
1107 debug!(
1109 "wake_timer_loop: START alarm_id: \"{}\", cid: {:?}\n\tdeadline: {}\n\tnow: {}",
1110 alarm_id,
1111 cid,
1112 format_timer(deadline.into()),
1113 format_timer(now.into()),
1114 );
1115
1116 if let fta::SetAndWaitMode::NotifySetupDone(setup_done) = mode {
1118 defer! {
1119 signal(&setup_done);
1121 debug!("wake_timer_loop: START: setup_done signaled");
1122 };
1123 }
1124 deadline_histogram_prop.insert((deadline - now).into_nanos());
1125 if Timers::expired(now, deadline) {
1126 trace::duration!(c"alarms", c"Cmd::Start:immediate");
1127 let (_lease, keep_alive) = zx::EventPair::create();
1129 debug!(
1130 "[{}] wake_timer_loop: bogus lease {:?}",
1131 line!(),
1132 &keep_alive.get_koid().unwrap()
1133 );
1134 responder
1135 .send(Ok(keep_alive))
1136 .map(|_| {
1137 debug!(
1138 concat!(
1139 "wake_timer_loop: cid: {:?}, alarm: {}: EXPIRED IMMEDIATELY\n\t",
1140 "deadline({}) <= now({})"
1141 ),
1142 cid,
1143 alarm_id,
1144 format_timer(deadline.into()),
1145 format_timer(now.into())
1146 )
1147 })
1148 .map_err(|e| {
1149 error!(
1150 "wake_timer_loop: cid: {:?}, alarm: {}: could not notify, dropping: {}",
1151 cid, alarm_id, e)
1152 })
1153 .unwrap_or(());
1154 } else {
1155 trace::duration!(c"alarms", c"Cmd::Start:regular");
1156 let was_empty = timers.is_empty();
1158
1159 let deadline_before = timers.peek_deadline();
1160 timers.push(TimerNode::new(deadline, alarm_id, cid, responder));
1161 let deadline_after = timers.peek_deadline();
1162
1163 let deadline_changed = is_deadline_changed(deadline_before, deadline_after);
1164 let needs_cancel = !was_empty && deadline_changed;
1165 let needs_reschedule = was_empty || deadline_changed;
1166
1167 if needs_reschedule {
1168 let schedulable_deadline = deadline_after.unwrap_or(deadline);
1170 if needs_cancel {
1171 stop_hrtimer(&timer_proxy, &timer_config).await;
1172 }
1173 hrtimer_status = Some(
1174 schedule_hrtimer(
1175 now,
1176 &timer_proxy,
1177 schedulable_deadline,
1178 snd.clone(),
1179 &timer_config,
1180 )
1181 .await,
1182 );
1183 }
1184 }
1185 }
1186 Cmd::StopById { timer_id, done } => {
1187 trace::duration!(c"alarms", c"Cmd::StopById", "alarm_id" => &timer_id.alarm_id[..]);
1188 debug!("wake_timer_loop: STOP timer: {}", timer_id);
1189 let deadline_before = timers.peek_deadline();
1190
1191 if let Some(mut timer_node) = timers.remove_by_id(&timer_id) {
1192 let deadline_after = timers.peek_deadline();
1193
1194 if let Some(responder) = timer_node.take_responder() {
1195 responder.send(Err(fta::WakeError::Dropped)).expect("infallible");
1197 }
1198 if is_deadline_changed(deadline_before, deadline_after) {
1199 stop_hrtimer(&timer_proxy, &timer_config).await;
1200 }
1201 if let Some(deadline) = deadline_after {
1202 let new_timer_state = schedule_hrtimer(
1205 now,
1206 &timer_proxy,
1207 deadline,
1208 snd.clone(),
1209 &timer_config,
1210 )
1211 .await;
1212 let old_hrtimer_status = hrtimer_status.replace(new_timer_state);
1213 if let Some(task) = old_hrtimer_status.map(|ev| ev.task) {
1214 task.await;
1216 }
1217 } else {
1218 hrtimer_status = None;
1220 }
1221 } else {
1222 debug!("wake_timer_loop: STOP: no active timer to stop: {}", timer_id);
1223 }
1224 signal(&done);
1225 }
1226 Cmd::Alarm { expired_deadline, keep_alive } => {
1227 trace::duration!(c"alarms", c"Cmd::Alarm");
1228 debug!(
1233 "wake_timer_loop: ALARM!!! reached deadline: {}, wakey-wakey! {:?}",
1234 format_timer(expired_deadline.into()),
1235 keep_alive.get_koid().unwrap(),
1236 );
1237 let expired_count =
1238 notify_all(&mut timers, &keep_alive, now).expect("notification succeeds");
1239 if expired_count == 0 {
1240 debug!("wake_timer_loop: no expired alarms, reset hrtimer state");
1243 stop_hrtimer(&timer_proxy, &timer_config).await;
1244 }
1245 hrtimer_status = match timers.peek_deadline() {
1247 None => None,
1248 Some(deadline) => Some(
1249 schedule_hrtimer(now, &timer_proxy, deadline, snd.clone(), &timer_config)
1250 .await,
1251 ),
1252 }
1253 }
1254 Cmd::AlarmFidlError { expired_deadline, error } => {
1255 trace::duration!(c"alarms", c"Cmd::AlarmFidlError");
1256 warn!(
1260 "wake_timer_loop: FIDL error: {:?}, deadline: {}, now: {}",
1261 error,
1262 format_timer(expired_deadline.into()),
1263 format_timer(now.into()),
1264 );
1265 let (_dummy_lease, peer) = zx::EventPair::create();
1268 debug!("XXX: [{}] bogus lease: 1 {:?}", line!(), &peer.get_koid().unwrap());
1269 notify_all(&mut timers, &peer, now).expect("notification succeeds");
1270 hrtimer_status = match timers.peek_deadline() {
1271 None => None, Some(deadline) => Some(
1273 schedule_hrtimer(now, &timer_proxy, deadline, snd.clone(), &timer_config)
1274 .await,
1275 ),
1276 }
1277 }
1278 Cmd::AlarmDriverError { expired_deadline, error } => {
1279 trace::duration!(c"alarms", c"Cmd::AlarmDriverError");
1280 let (_dummy_lease, peer) = zx::EventPair::create();
1281 debug!("XXX: [{}] bogus lease: {:?}", line!(), &peer.get_koid().unwrap());
1282 notify_all(&mut timers, &peer, now).expect("notification succeeds");
1283 match error {
1284 fidl_fuchsia_hardware_hrtimer::DriverError::Canceled => {
1285 debug!(
1287 "wake_timer_loop: CANCELED timer at deadline: {}",
1288 format_timer(expired_deadline.into())
1289 );
1290 }
1291 _ => {
1292 error!(
1293 "wake_timer_loop: DRIVER SAYS: {:?}, deadline: {}, now: {}",
1294 error,
1295 format_timer(expired_deadline.into()),
1296 format_timer(now.into()),
1297 );
1298 hrtimer_status = match timers.peek_deadline() {
1302 None => None,
1303 Some(deadline) => Some(
1304 schedule_hrtimer(
1305 now,
1306 &timer_proxy,
1307 deadline,
1308 snd.clone(),
1309 &timer_config,
1310 )
1311 .await,
1312 ),
1313 }
1314 }
1315 }
1316 }
1317 }
1318
1319 {
1320 trace::duration!(c"timekeeper", c"inspect");
1325 let now_formatted = format_timer(now.into());
1326 debug!("wake_timer_loop: now: {}", &now_formatted);
1327 now_formatted_prop.set(&now_formatted);
1328
1329 let pending_timers_count: u64 =
1330 timers.timer_count().try_into().expect("always convertible");
1331 debug!("wake_timer_loop: currently pending timer count: {}", pending_timers_count);
1332 pending_timers_count_prop.set(pending_timers_count);
1333
1334 let pending_timers = format!("{}", timers);
1335 debug!("wake_timer_loop: currently pending timers: {}", &timers);
1336 pending_timers_prop.set(&pending_timers);
1337
1338 let current_deadline: String = hrtimer_status
1339 .as_ref()
1340 .map(|s| format!("{}", format_timer(s.deadline.into())))
1341 .unwrap_or_else(|| "(none)".into());
1342 debug!("wake_timer_loop: current hardware timer deadline: {:?}", current_deadline);
1343 current_hw_deadline_prop.set(¤t_deadline);
1344
1345 let remaining_duration_until_alarm = hrtimer_status
1346 .as_ref()
1347 .map(|s| format!("{}", format_duration((s.deadline - now).into())))
1348 .unwrap_or_else(|| "(none)".into());
1349 debug!(
1350 "wake_timer_loop: remaining duration until alarm: {}",
1351 &remaining_duration_until_alarm
1352 );
1353 remaining_until_alarm_prop.set(&remaining_duration_until_alarm);
1354 debug!("---");
1355 }
1356 }
1357
1358 debug!("wake_timer_loop: exiting. This is unlikely in prod code.");
1359}
1360
1361async fn schedule_hrtimer(
1372 now: fasync::BootInstant,
1373 hrtimer: &Box<dyn TimerOps>,
1374 deadline: fasync::BootInstant,
1375 mut command_send: mpsc::Sender<Cmd>,
1376 timer_config: &TimerConfig,
1377) -> TimerState {
1378 let timeout = std::cmp::max(zx::BootDuration::ZERO, deadline - now);
1379 trace::duration!(c"alarms", c"schedule_hrtimer", "timeout" => timeout.into_nanos());
1380 let hrtimer_scheduled = zx::Event::create();
1382
1383 debug!(
1384 "schedule_hrtimer:\n\tnow: {}\n\tdeadline: {}\n\ttimeout: {}",
1385 format_timer(now.into()),
1386 format_timer(deadline.into()),
1387 format_duration(timeout),
1388 );
1389
1390 let slack = timer_config.pick_setting(timeout);
1391
1392 let resolution_nanos = slack.resolution.into_nanos();
1393 let ticks = slack.ticks();
1394 trace::instant!(c"alarms", c"hrtimer:programmed",
1395 trace::Scope::Process,
1396 "resolution_ns" => resolution_nanos,
1397 "ticks" => ticks
1398 );
1399 let start_and_wait_fut = hrtimer.start_and_wait(
1400 timer_config.id,
1401 &ffhh::Resolution::Duration(resolution_nanos),
1402 ticks,
1403 clone_handle(&hrtimer_scheduled),
1404 );
1405 let hrtimer_task = fasync::Task::local(async move {
1406 debug!("hrtimer_task: waiting for hrtimer driver response");
1407 trace::instant!(c"alarms", c"hrtimer:started", trace::Scope::Process);
1408 let response = start_and_wait_fut.await;
1409 trace::instant!(c"alarms", c"hrtimer:response", trace::Scope::Process);
1410 match response {
1411 Err(TimerOpsError::Fidl(e)) => {
1412 trace::instant!(c"alarms", c"hrtimer:response:fidl_error", trace::Scope::Process);
1413 debug!("hrtimer_task: hrtimer FIDL error: {:?}", e);
1414 command_send
1415 .start_send(Cmd::AlarmFidlError { expired_deadline: now, error: e })
1416 .unwrap();
1417 }
1419 Err(TimerOpsError::Driver(e)) => {
1420 let driver_error_str = format!("{:?}", e);
1421 trace::instant!(c"alarms", c"hrtimer:response:driver_error", trace::Scope::Process, "error" => &driver_error_str[..]);
1422 debug!("schedule_hrtimer: hrtimer driver error: {:?}", e);
1423 command_send
1424 .start_send(Cmd::AlarmDriverError { expired_deadline: now, error: e })
1425 .unwrap();
1426 }
1428 Ok(keep_alive) => {
1429 trace::instant!(c"alarms", c"hrtimer:response:alarm", trace::Scope::Process);
1430 debug!("hrtimer: got alarm response: {:?}", keep_alive);
1431 command_send
1433 .start_send(Cmd::Alarm { expired_deadline: deadline, keep_alive })
1434 .unwrap();
1435 }
1436 }
1437 debug!("hrtimer_task: exiting task.");
1438 trace::instant!(c"alarms", c"hrtimer:task_exit", trace::Scope::Process);
1439 });
1440 debug!("schedule_hrtimer: waiting for event to be signaled");
1441
1442 wait_signaled(&hrtimer_scheduled).await;
1444 let now_after_signaled = fasync::BootInstant::now();
1445 let duration_until_scheduled: zx::BootDuration = (now_after_signaled - now).into();
1446 if duration_until_scheduled > zx::BootDuration::from_nanos(1000 * MSEC_IN_NANOS) {
1447 trace::duration!(c"alarms", c"schedule_hrtimer:unusual_duration",
1448 "duration" => duration_until_scheduled.into_nanos());
1449 warn!(
1450 "unusual duration until hrtimer scheduled: {}",
1451 format_duration(duration_until_scheduled)
1452 );
1453 }
1454 debug!("schedule_hrtimer: hrtimer wake alarm has been scheduled.");
1455 TimerState { task: hrtimer_task, deadline }
1456}
1457
1458fn notify_all(
1468 timers: &mut Timers,
1469 lease_prototype: &zx::EventPair,
1470 reference_instant: fasync::BootInstant,
1471) -> Result<usize> {
1472 trace::duration!(c"alarms", c"notify_all");
1473 let now = fasync::BootInstant::now();
1474 let mut expired = 0;
1475 while let Some(mut timer_node) = timers.maybe_expire_earliest(reference_instant) {
1476 expired += 1;
1477 let deadline = *timer_node.get_deadline();
1479 let alarm_id = timer_node.get_alarm_id().to_string();
1480 let cid = timer_node.get_cid().clone();
1481 let slack: zx::BootDuration = deadline - now;
1482 if slack < zx::BootDuration::from_nanos(-1000 * MSEC_IN_NANOS) {
1483 trace::duration!(c"alarms", c"schedule_hrtimer:unusual_slack", "slack" => slack.into_nanos());
1484 warn!(
1486 "alarm id: {} had an unusually large slack: {}",
1487 alarm_id,
1488 format_duration(slack)
1489 );
1490 }
1491 debug!(
1492 concat!(
1493 "wake_alarm_loop: ALARM alarm_id: \"{}\"\n\tdeadline: {},\n\tcid: {:?},\n\t",
1494 "reference_instant: {},\n\tnow: {},\n\tslack: {}",
1495 ),
1496 alarm_id,
1497 format_timer(deadline.into()),
1498 cid,
1499 format_timer(reference_instant.into()),
1500 format_timer(now.into()),
1501 format_duration(slack),
1502 );
1503 let lease = clone_handle(lease_prototype);
1504 trace::instant!(c"alarms", c"notify", trace::Scope::Process, "alarm_id" => &alarm_id[..], "cid" => cid);
1505 let _ = timer_node
1506 .take_responder()
1507 .map(|r| r.send(Ok(lease)))
1508 .map_or_else(|| Ok(()), |res| res)
1509 .map_err(|e| error!("could not signal responder: {:?}", e));
1510 trace::instant!(c"alarms", c"notified", trace::Scope::Process);
1511 }
1512 trace::instant!(c"alarms", c"notify", trace::Scope::Process, "expired_count" => expired);
1513 debug!("notify_all: expired count: {}", expired);
1514 Ok(expired)
1515 }
1517
1518const HRTIMER_DIRECTORY: &str = "/dev/class/hrtimer";
1521
1522pub fn connect_to_hrtimer_async() -> Result<ffhh::DeviceProxy> {
1524 debug!("connect_to_hrtimer: trying directory: {}", HRTIMER_DIRECTORY);
1525 let mut dir = std::fs::read_dir(HRTIMER_DIRECTORY)
1526 .map_err(|e| anyhow!("Failed to open hrtimer directory: {e}"))?;
1527 let entry = dir
1528 .next()
1529 .ok_or_else(|| anyhow!("No entry in the hrtimer directory"))?
1530 .map_err(|e| anyhow!("Failed to find hrtimer device: {e}"))?;
1531 let path = entry
1532 .path()
1533 .into_os_string()
1534 .into_string()
1535 .map_err(|e| anyhow!("Failed to parse the device entry path: {e:?}"))?;
1536
1537 let (hrtimer, server_end) = fidl::endpoints::create_proxy::<ffhh::DeviceMarker>();
1538 fdio::service_connect(&path, server_end.into_channel())
1539 .map_err(|e| anyhow!("Failed to open hrtimer device: {e}"))?;
1540
1541 Ok(hrtimer)
1542}
1543
1544#[cfg(test)]
1545mod tests {
1546 use super::*;
1547 use diagnostics_assertions::{assert_data_tree, AnyProperty};
1548 use futures::{select, Future};
1549 use std::task::Poll;
1550 use test_case::test_case;
1551 use test_util::{assert_gt, assert_lt};
1552
1553 fn run_in_fake_time_and_test_context<F, U, T>(
1562 run_for_duration: zx::MonotonicDuration,
1563 test_fn_factory: F,
1564 ) where
1565 F: FnOnce(fta::WakeProxy, finspect::Inspector) -> U, U: Future<Output = T> + 'static, T: 'static,
1568 {
1569 let mut exec = fasync::TestExecutor::new_with_fake_time(); exec.set_fake_time(fasync::MonotonicInstant::from_nanos(0));
1571 let (mut fake_commands_in, fake_commands_out) = mpsc::channel::<FakeCmd>(0);
1572 let (hrtimer_proxy, hrtimer_task) = fake_hrtimer_connection(fake_commands_out);
1573 let inspector = finspect::component::inspector();
1574 let alarms = Rc::new(Loop::new(hrtimer_proxy, inspector.root().create_child("test")));
1575
1576 let (_handle, peer) = zx::EventPair::create();
1577
1578 let done_set_properties = zx::Event::create();
1579 let begin_test = clone_handle(&done_set_properties);
1580 let begin_serve = clone_handle(&done_set_properties);
1581
1582 let mut fake_commands_in_clone = fake_commands_in.clone();
1583 let config_task = async move {
1584 fake_commands_in
1585 .start_send(FakeCmd::SetProperties {
1586 resolutions: vec![zx::Duration::from_nanos(43)],
1587 max_ticks: 100,
1588 keep_alive: peer,
1589 done: clone_handle(&done_set_properties),
1590 })
1591 .unwrap();
1592 };
1593
1594 let (wake_proxy, wake_stream) =
1595 fidl::endpoints::create_proxy_and_stream::<fta::WakeMarker>();
1596
1597 let serving_task = async move {
1598 fasync::OnSignals::new(begin_serve, zx::Signals::EVENT_SIGNALED).await.unwrap();
1599 serve(alarms, wake_stream).await;
1600 };
1601
1602 let seq_fn_fut = test_fn_factory(wake_proxy, inspector.clone());
1603
1604 let test_task = async move {
1605 fasync::OnSignals::new(begin_test, zx::Signals::EVENT_SIGNALED).await.unwrap();
1607
1608 let result = seq_fn_fut.await;
1609
1610 fake_commands_in_clone.start_send(FakeCmd::Exit).unwrap();
1612 result
1613 };
1614
1615 let mut main_fut = fasync::Task::local(async {
1616 let _r = futures::join!(hrtimer_task, config_task, serving_task, test_task);
1617 });
1618 run_in_fake_time(&mut exec, &mut main_fut, run_for_duration);
1619 }
1620
1621 fn run_in_fake_time<F>(
1630 executor: &mut fasync::TestExecutor,
1631 main_fut: &mut F,
1632 total_duration: zx::MonotonicDuration,
1633 ) where
1634 F: Future<Output = ()> + Unpin,
1635 {
1636 const INCREMENT: zx::MonotonicDuration = zx::MonotonicDuration::from_nanos(13);
1637 let mut current = zx::MonotonicDuration::ZERO;
1638 let mut poll_status = Poll::Pending;
1639
1640 while current < (total_duration + INCREMENT) && poll_status == Poll::Pending {
1645 let next = executor.now() + INCREMENT;
1646 executor.set_fake_time(next);
1647 executor.wake_expired_timers();
1648 poll_status = executor.run_until_stalled(main_fut);
1649 current = current + INCREMENT;
1650 }
1651 let now = executor.now();
1652 assert_eq!(
1653 poll_status,
1654 Poll::Ready(()),
1655 "the main future did not complete at {}, perhaps increase total_duration?",
1656 format_timer(now.into())
1657 );
1658 }
1659
1660 fn create_fake_wake_lease() -> fidl_fuchsia_power_system::LeaseToken {
1661 let (_lease, peer) = zx::EventPair::create();
1662 peer
1663 }
1664
1665 #[test]
1666 fn timer_duration_no_overflow() {
1667 let duration1 = TimerDuration {
1668 resolution: zx::BootDuration::from_seconds(100_000_000),
1669 ticks: u64::MAX,
1670 };
1671 let duration2 = TimerDuration {
1672 resolution: zx::BootDuration::from_seconds(110_000_000),
1673 ticks: u64::MAX,
1674 };
1675 assert_eq!(duration1, duration1);
1676 assert_eq!(duration2, duration2);
1677
1678 assert_lt!(duration1, duration2);
1679 assert_gt!(duration2, duration1);
1680 }
1681
1682 #[test_case(
1683 TimerDuration::new(zx::BootDuration::from_nanos(1), 1),
1684 TimerDuration::new(zx::BootDuration::from_nanos(1), 1)
1685 )]
1686 #[test_case(
1687 TimerDuration::new(zx::BootDuration::from_nanos(1), 10),
1688 TimerDuration::new(zx::BootDuration::from_nanos(10), 1)
1689 )]
1690 #[test_case(
1691 TimerDuration::new(zx::BootDuration::from_nanos(10), 1),
1692 TimerDuration::new(zx::BootDuration::from_nanos(1), 10)
1693 )]
1694 #[test_case(
1695 TimerDuration::new(zx::BootDuration::from_micros(1), 1),
1696 TimerDuration::new(zx::BootDuration::from_nanos(1), 1000)
1697 )]
1698 fn test_slack_eq(one: TimerDuration, other: TimerDuration) {
1699 assert_eq!(one, other);
1700 }
1701
1702 #[test_case(
1703 TimerDuration::new(zx::BootDuration::from_nanos(1), 1),
1704 TimerDuration::new(zx::BootDuration::from_nanos(1), 2)
1705 )]
1706 #[test_case(
1707 TimerDuration::new(zx::BootDuration::from_nanos(1), 1),
1708 TimerDuration::new(zx::BootDuration::from_nanos(10), 1)
1709 )]
1710 fn test_slack_lt(one: TimerDuration, other: TimerDuration) {
1711 assert_lt!(one, other);
1712 }
1713
1714 #[test_case(
1715 TimerDuration::new(zx::BootDuration::from_nanos(1), 2),
1716 TimerDuration::new(zx::BootDuration::from_nanos(1), 1)
1717 )]
1718 #[test_case(
1719 TimerDuration::new(zx::BootDuration::from_nanos(10), 1),
1720 TimerDuration::new(zx::BootDuration::from_nanos(1), 1)
1721 )]
1722 fn test_slack_gt(one: TimerDuration, other: TimerDuration) {
1723 assert_gt!(one, other);
1724 }
1725
1726 #[test_case(
1727 vec![zx::BootDuration::from_nanos(1)],
1728 100,
1729 zx::BootDuration::from_nanos(0),
1730 TimerDuration::new(zx::BootDuration::from_nanos(1), 0) ; "Exact at 0x1ns"
1731 )]
1732 #[test_case(
1733 vec![zx::BootDuration::from_nanos(1)],
1734 100,
1735 zx::BootDuration::from_nanos(50),
1736 TimerDuration::new(zx::BootDuration::from_nanos(1), 50) ; "Exact at 50x1ns"
1737 )]
1738 #[test_case(
1739 vec![zx::BootDuration::from_nanos(2)],
1740 100,
1741 zx::BootDuration::from_nanos(50),
1742 TimerDuration::new(zx::BootDuration::from_nanos(2), 25) ; "Exact at 25x2ns"
1743 )]
1744 #[test_case(
1745 vec![zx::BootDuration::from_nanos(3)],
1746 100,
1747 zx::BootDuration::from_nanos(50),
1748 TimerDuration::new(zx::BootDuration::from_nanos(3), 17) ; "Inexact at 51ns"
1750 )]
1751 #[test_case(
1752 vec![
1753 zx::BootDuration::from_nanos(3),
1754 zx::BootDuration::from_nanos(4)
1755 ],
1756 100,
1757 zx::BootDuration::from_nanos(50),
1758 TimerDuration::new(zx::BootDuration::from_nanos(3), 17) ; "3ns is a better resolution"
1759 )]
1760 #[test_case(
1761 vec![
1762 zx::BootDuration::from_nanos(1000),
1763 ],
1764 100,
1765 zx::BootDuration::from_nanos(50),
1766 TimerDuration::new(zx::BootDuration::from_nanos(1000), 1) ;
1767 "950ns negative slack is the best we can do"
1768 )]
1769 #[test_case(
1770 vec![
1771 zx::BootDuration::from_nanos(1),
1772 ],
1773 10,
1774 zx::BootDuration::from_nanos(50),
1775 TimerDuration::new(zx::BootDuration::from_nanos(1), 10) ;
1776 "10ns positive slack is the best we can do"
1777 )]
1778 #[test_case(
1779 vec![
1780 zx::BootDuration::from_millis(1),
1781 zx::BootDuration::from_micros(100),
1782 zx::BootDuration::from_micros(10),
1783 zx::BootDuration::from_micros(1),
1784 ],
1785 20, zx::BootDuration::from_micros(150),
1787 TimerDuration::new(zx::BootDuration::from_micros(10), 15) ;
1788 "Realistic case with resolutions from driver, should be 15us"
1789 )]
1790 #[test_case(
1791 vec![
1792 zx::BootDuration::from_millis(1),
1793 zx::BootDuration::from_micros(100),
1794 zx::BootDuration::from_micros(10),
1795 zx::BootDuration::from_micros(1),
1796 ],
1797 2000, zx::BootDuration::from_micros(6000),
1799 TimerDuration::new(zx::BootDuration::from_millis(1), 6) ;
1800 "Coarser exact unit wins"
1801 )]
1802 fn test_pick_setting(
1803 resolutions: Vec<zx::BootDuration>,
1804 max_ticks: u64,
1805 duration: zx::BootDuration,
1806 expected: TimerDuration,
1807 ) {
1808 let config = TimerConfig::new_from_data(MAIN_TIMER_ID as u64, &resolutions[..], max_ticks);
1809 let actual = config.pick_setting(duration);
1810
1811 assert_slack_eq(expected, actual);
1814 }
1815
1816 fn assert_slack_eq(expected: TimerDuration, actual: TimerDuration) {
1818 let slack = expected.duration() - actual.duration();
1819 assert_eq!(
1820 actual.resolution(),
1821 expected.resolution(),
1822 "\n\texpected: {} ({})\n\tactual : {} ({})\n\tslack: expected-actual={}",
1823 expected,
1824 format_duration(expected.duration()),
1825 actual,
1826 format_duration(actual.duration()),
1827 format_duration(slack)
1828 );
1829 assert_eq!(
1830 actual.ticks(),
1831 expected.ticks(),
1832 "\n\texpected: {} ({})\n\tactual : {} ({})\n\tslack: expected-actual={}",
1833 expected,
1834 format_duration(expected.duration()),
1835 actual,
1836 format_duration(actual.duration()),
1837 format_duration(slack)
1838 );
1839 }
1840
1841 #[derive(Debug)]
1842 enum FakeCmd {
1843 SetProperties {
1844 resolutions: Vec<zx::BootDuration>,
1845 max_ticks: i64,
1846 keep_alive: zx::EventPair,
1847 done: zx::Event,
1848 },
1849 Exit,
1850 }
1851
1852 use std::cell::RefCell;
1853 use std::rc::Rc;
1854
1855 fn fake_hrtimer_connection(
1861 rcv: mpsc::Receiver<FakeCmd>,
1862 ) -> (ffhh::DeviceProxy, fasync::Task<()>) {
1863 debug!("fake_hrtimer_connection: entry.");
1864 let (hrtimer, mut stream) =
1865 fidl::endpoints::create_proxy_and_stream::<ffhh::DeviceMarker>();
1866 let task = fasync::Task::local(async move {
1867 let mut rcv = rcv.fuse();
1868 let timer_properties = Rc::new(RefCell::new(None));
1869 let wake_lease = Rc::new(RefCell::new(None));
1870
1871 let timer_running = Rc::new(RefCell::new(false));
1875
1876 loop {
1877 let timer_properties = timer_properties.clone();
1878 let wake_lease = wake_lease.clone();
1879 select! {
1880 cmd = rcv.next() => {
1881 debug!("fake_hrtimer_connection: cmd: {:?}", cmd);
1882 match cmd {
1883 Some(FakeCmd::Exit) => { break; }
1884 Some(FakeCmd::SetProperties{ resolutions, max_ticks, keep_alive, done}) => {
1885 let mut timer_props = vec![];
1886 for v in 0..10 {
1887 timer_props.push(ffhh::TimerProperties {
1888 supported_resolutions: Some(
1889 resolutions.iter()
1890 .map(|d| ffhh::Resolution::Duration(d.into_nanos())).collect()),
1891 max_ticks: Some(max_ticks.try_into().unwrap()),
1892 supports_wait: Some(true),
1894 id: Some(v),
1895 ..Default::default()
1896 },
1897 );
1898 }
1899 *timer_properties.borrow_mut() = Some(timer_props);
1900 *wake_lease.borrow_mut() = Some(keep_alive);
1901 debug!("set timer properties to: {:?}", timer_properties);
1902 signal(&done);
1903 }
1904 e => {
1905 panic!("unrecognized command: {:?}", e);
1906 }
1907 }
1908 },
1910 event = stream.next() => {
1911 debug!("fake_hrtimer_connection: event: {:?}", event);
1912 if let Some(Ok(event)) = event {
1913 match event {
1914 ffhh::DeviceRequest::Start { responder, .. } => {
1915 assert!(!*timer_running.borrow(), "invariant broken: timer may not be running here");
1916 *timer_running.borrow_mut() = true;
1917 responder.send(Ok(())).expect("");
1918 }
1919 ffhh::DeviceRequest::Stop { responder, .. } => {
1920 *timer_running.borrow_mut() = false;
1921 responder.send(Ok(())).expect("");
1922 }
1923 ffhh::DeviceRequest::GetTicksLeft { responder, .. } => {
1924 responder.send(Ok(1)).expect("");
1925 }
1926 ffhh::DeviceRequest::SetEvent { responder, .. } => {
1927 responder.send(Ok(())).expect("");
1928 }
1929 ffhh::DeviceRequest::StartAndWait { id, resolution, ticks, setup_event, responder, .. } => {
1930 assert!(!*timer_running.borrow(), "invariant broken: timer may not be running here");
1931 *timer_running.borrow_mut() = true;
1932 debug!("fake_hrtimer_connection: starting timer: \"{}\", resolution: {:?}, ticks: {}", id, resolution, ticks);
1933 let ticks: i64 = ticks.try_into().unwrap();
1934 let sleep_duration = zx::BootDuration::from_nanos(ticks * match resolution {
1935 ffhh::Resolution::Duration(e) => e,
1936 _ => {
1937 error!("resolution has an unexpected value");
1938 1
1939 }
1940 });
1941 let timer_running_clone = timer_running.clone();
1942 fasync::Task::local(async move {
1943 fasync::Timer::new(sleep_duration).await;
1946 *timer_running_clone.borrow_mut() = false;
1947 responder.send(Ok(clone_handle(wake_lease.borrow().as_ref().unwrap()))).unwrap();
1948
1949 signal(&setup_event);
1952
1953 }).detach();
1954 }
1955 ffhh::DeviceRequest::StartAndWait2 { responder, .. } => {
1956 assert!(!*timer_running.borrow(), "invariant broken: timer may not be running here");
1957 *timer_running.borrow_mut() = true;
1958 responder.send(Err(ffhh::DriverError::InternalError)).expect("");
1959 }
1960 ffhh::DeviceRequest::GetProperties { responder, .. } => {
1961 if (*timer_properties).borrow().is_none() {
1962 error!("timer_properties is empty, this is not what you want!");
1963 }
1964 responder
1965 .send(ffhh::Properties {
1966 timers_properties: (*timer_properties).borrow().clone(),
1967 ..Default::default()
1968 })
1969 .expect("");
1970 }
1971 ffhh::DeviceRequest::ReadTimer { responder, .. } => {
1972 responder.send(Err(ffhh::DriverError::NotSupported)).expect("");
1973 }
1974 ffhh::DeviceRequest::ReadClock { responder, .. } => {
1975 responder.send(Err(ffhh::DriverError::NotSupported)).expect("");
1976 }
1977 ffhh::DeviceRequest::_UnknownMethod { .. } => todo!(),
1978 }
1979 }
1980 },
1981 }
1982 }
1983 debug!("fake_hrtimer_connection: exiting");
1984 });
1985 (hrtimer, task)
1986 }
1987
1988 #[fuchsia::test]
1989 fn test_basic_timed_wait() {
1990 let deadline = zx::BootInstant::from_nanos(100);
1991 let test_duration = zx::MonotonicDuration::from_nanos(110);
1992 run_in_fake_time_and_test_context(test_duration, |wake_proxy, _| async move {
1993 let setup_done = zx::Event::create();
1994 let duplicate = clone_handle(&setup_done);
1995
1996 wake_proxy
1997 .set_and_wait(
1998 deadline.into(),
1999 fta::SetAndWaitMode::NotifySetupDone(setup_done),
2000 "Hello".into(),
2001 )
2002 .await
2003 .unwrap()
2004 .unwrap();
2005
2006 assert_gt!(fasync::BootInstant::now().into_nanos(), deadline.into_nanos());
2007
2008 let signals = duplicate
2011 .wait_handle(zx::Signals::EVENT_SIGNALED, zx::MonotonicInstant::INFINITE_PAST)
2012 .unwrap();
2013 assert_eq!(signals, zx::Signals::EVENT_SIGNALED);
2014 });
2015 }
2016
2017 #[test_case(
2018 zx::BootInstant::from_nanos(100),
2019 zx::BootInstant::from_nanos(200),
2020 zx::MonotonicDuration::from_nanos(250) ;
2021 "Two timers: one at 100 and another at 200 ns"
2022 )]
2023 #[test_case(
2024 zx::BootInstant::from_nanos(100),
2025 zx::BootInstant::from_nanos(100),
2026 zx::MonotonicDuration::from_nanos(104) ;
2028 "Two timers at the same deadline."
2029 )]
2030 #[test_case(
2031 zx::BootInstant::from_nanos(-1),
2032 zx::BootInstant::from_nanos(-1),
2033 zx::MonotonicDuration::from_nanos(30) ;
2034 "Two timers expire immediately."
2035 )]
2036 #[fuchsia::test]
2037 fn test_timed_wait_two_timers_params(
2038 first_deadline: zx::BootInstant,
2040 second_deadline: zx::BootInstant,
2042 duration: zx::MonotonicDuration,
2044 ) {
2045 run_in_fake_time_and_test_context(duration, |wake_proxy, _| async move {
2046 let lease1 = fta::SetAndWaitMode::KeepAlive(create_fake_wake_lease());
2047 let fut1 = wake_proxy.set_and_wait(first_deadline.into(), lease1, "Hello1".into());
2048
2049 let lease2 = fta::SetAndWaitMode::KeepAlive(create_fake_wake_lease());
2050 let fut2 = wake_proxy.set_and_wait(second_deadline.into(), lease2, "Hello2".into());
2051
2052 let (result1, result2) = futures::join!(fut1, fut2);
2053
2054 result1.unwrap().unwrap();
2055 result2.unwrap().unwrap();
2056
2057 assert_gt!(fasync::BootInstant::now().into_nanos(), first_deadline.into_nanos());
2058 assert_gt!(fasync::BootInstant::now().into_nanos(), second_deadline.into_nanos());
2059 });
2060 }
2061
2062 #[test_case(
2063 zx::BootInstant::from_nanos(100),
2064 zx::BootInstant::from_nanos(200),
2065 zx::MonotonicDuration::from_nanos(250) ;
2066 "Reschedule with push-out"
2067 )]
2068 #[test_case(
2069 zx::BootInstant::from_nanos(100),
2070 zx::BootInstant::from_nanos(100),
2071 zx::MonotonicDuration::from_nanos(104) ;
2073 "Reschedule with same deadline"
2074 )]
2075 #[test_case(
2076 zx::BootInstant::from_nanos(200),
2077 zx::BootInstant::from_nanos(100),
2078 zx::MonotonicDuration::from_nanos(240) ;
2080 "Pull in"
2081 )]
2082 #[fuchsia::test]
2083 fn test_timed_wait_same_timer(
2084 first_deadline: zx::BootInstant,
2086 second_deadline: zx::BootInstant,
2088 duration: zx::MonotonicDuration,
2090 ) {
2091 run_in_fake_time_and_test_context(duration, |wake_proxy, _| async move {
2092 let lease1 = fta::SetAndWaitMode::KeepAlive(create_fake_wake_lease());
2093
2094 wake_proxy
2095 .set_and_wait(first_deadline.into(), lease1, "Hello".into())
2096 .await
2097 .unwrap()
2098 .unwrap();
2099 let lease2 = fta::SetAndWaitMode::KeepAlive(create_fake_wake_lease());
2100 wake_proxy
2101 .set_and_wait(second_deadline.into(), lease2, "Hello2".into())
2102 .await
2103 .unwrap()
2104 .unwrap();
2105 });
2106 }
2107
2108 #[fuchsia::test]
2111 fn test_reschedule_pull_in() {
2112 const LONG_DEADLINE_NANOS: i64 = 200;
2113 const SHORT_DEADLINE_NANOS: i64 = 100;
2114 const ALARM_ID: &str = "Hello";
2115 run_in_fake_time_and_test_context(
2116 zx::MonotonicDuration::from_nanos(LONG_DEADLINE_NANOS + 50),
2117 |wake_proxy, _| async move {
2118 let wake_proxy = Rc::new(RefCell::new(wake_proxy));
2119
2120 let keep_alive = fta::SetAndWaitMode::KeepAlive(create_fake_wake_lease());
2121
2122 let (mut sync_send, mut sync_recv) = mpsc::channel(1);
2123
2124 let wake_proxy_clone = wake_proxy.clone();
2127 let long_deadline_fut = async move {
2128 let wake_fut = wake_proxy_clone.borrow().set_and_wait(
2129 zx::BootInstant::from_nanos(LONG_DEADLINE_NANOS).into(),
2130 keep_alive,
2131 ALARM_ID.into(),
2132 );
2133 sync_send.send(()).await.unwrap();
2135
2136 wake_fut.await.unwrap().unwrap();
2138 };
2139
2140 let short_deadline_fut = async move {
2144 let _ = sync_recv.next().await;
2146
2147 let keep_alive2 = fta::SetAndWaitMode::KeepAlive(create_fake_wake_lease());
2148 let _ = wake_proxy
2149 .borrow()
2150 .set_and_wait(
2151 zx::BootInstant::from_nanos(SHORT_DEADLINE_NANOS).into(),
2152 keep_alive2,
2153 ALARM_ID.into(),
2154 )
2155 .await
2156 .unwrap()
2157 .unwrap();
2158
2159 assert_gt!(fasync::BootInstant::now().into_nanos(), SHORT_DEADLINE_NANOS);
2161 assert_lt!(fasync::BootInstant::now().into_nanos(), LONG_DEADLINE_NANOS);
2162 };
2163 futures::join!(short_deadline_fut, long_deadline_fut);
2164 },
2165 );
2166 }
2167
2168 #[fuchsia::test]
2171 fn test_reschedule_push_out() {
2172 const LONG_DEADLINE_NANOS: i64 = 200;
2173 const SHORT_DEADLINE_NANOS: i64 = 100;
2174 const ALARM_ID: &str = "Hello";
2175 run_in_fake_time_and_test_context(
2176 zx::MonotonicDuration::from_nanos(LONG_DEADLINE_NANOS + 50),
2177 |wake_proxy, inspector| async move {
2178 let wake_proxy = Rc::new(RefCell::new(wake_proxy));
2179
2180 let keep_alive = fta::SetAndWaitMode::KeepAlive(create_fake_wake_lease());
2181
2182 let (mut sync_send, mut sync_recv) = mpsc::channel(1);
2183
2184 let wake_proxy_clone = wake_proxy.clone();
2187 let short_deadline_fut = async move {
2188 let wake_fut = wake_proxy_clone.borrow().set_and_wait(
2189 zx::BootInstant::from_nanos(SHORT_DEADLINE_NANOS).into(),
2190 keep_alive,
2191 ALARM_ID.into(),
2192 );
2193 sync_send.send(()).await.unwrap();
2195
2196 let result = wake_fut.await.unwrap();
2198 assert_eq!(
2199 result,
2200 Err(fta::WakeError::Dropped),
2201 "expected wake alarm to be dropped"
2202 );
2203 assert_gt!(fasync::BootInstant::now().into_nanos(), SHORT_DEADLINE_NANOS);
2204 };
2205
2206 let long_deadline_fut = async move {
2210 let _ = sync_recv.next().await;
2212
2213 let keep_alive2 = fta::SetAndWaitMode::KeepAlive(create_fake_wake_lease());
2214 let _ = wake_proxy
2215 .borrow()
2216 .set_and_wait(
2217 zx::BootInstant::from_nanos(LONG_DEADLINE_NANOS).into(),
2218 keep_alive2,
2219 ALARM_ID.into(),
2220 )
2221 .await
2222 .unwrap()
2223 .unwrap();
2224
2225 assert_gt!(fasync::BootInstant::now().into_nanos(), LONG_DEADLINE_NANOS);
2227 };
2228 futures::join!(long_deadline_fut, short_deadline_fut);
2229
2230 assert_data_tree!(inspector, root: {
2233 test: {
2234 hardware: {
2235 current_deadline: "(none)",
2237 remaining_until_alarm: "(none)",
2238 },
2239 now_formatted: "247ns (247)",
2240 now_ns: 247i64,
2241 pending_timers: "\n\t",
2242 pending_timers_count: 0u64,
2243 requested_deadlines_ns: AnyProperty,
2244 },
2245 });
2246 },
2247 );
2248 }
2249}