Adds back a host/systime for demo only.

filter it behind a feature flag (#927)

* This fixes the unstable timings in sim

* Adds back a host/systime for demo only.

filter it behind a feature flag

* Update core/cu29_runtime/src/curuntime.rs

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

---------

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

Author: gbin

core/cu29/Cargo.toml

@@ -47,6 +47,7 @@ units = ["dep:cu29-units"]
 macro_debug = ["cu29-derive/macro_debug", "cu29-log-derive/macro_debug"]
 logviz = ["cu29-derive/logviz"]
 signal-handler = ["dep:ctrlc", "cu29-derive/signal-handler"]
+sysclock-perf = ["std", "cu29-runtime/sysclock-perf"]
 log-level-debug = ["cu29-log-derive/log-level-debug"]
 log-level-info = ["cu29-log-derive/log-level-info"]
 log-level-warning = ["cu29-log-derive/log-level-warning"]

core/cu29/src/lib.rs

@@ -25,6 +25,7 @@
 //! - `reflect`: reflection support for runtime and units types
 //! - `textlogs`: text logging derive support
 //! - `remote-debug`: remote debug transport support
+//! - `sysclock-perf`: use a host/system clock for runtime perf timing while keeping robot time for `tov`
 //!
 //! ## Concepts behind Copper
 //!

core/cu29_derive/src/lib.rs

@@ -2455,7 +2455,7 @@ pub fn copper_runtime(args: TokenStream, input: TokenStream) -> TokenStream {
         let run_loop = if std {
             quote! {
                 loop  {
-                    let iter_start = self.copper_runtime.clock.now();
+                    let iter_start = cu29::curuntime::perf_now(&self.copper_runtime.clock);
                     let result = match std::panic::catch_unwind(std::panic::AssertUnwindSafe(
                         || <Self as #app_trait<S, L>>::run_one_iteration(self, #sim_callback_arg)
                     )) {
@@ -2478,7 +2478,7 @@ pub fn copper_runtime(args: TokenStream, input: TokenStream) -> TokenStream {
 
                     if let Some(rate) = self.copper_runtime.runtime_config.rate_target_hz {
                         let period: CuDuration = (1_000_000_000u64 / rate).into();
-                        let elapsed = self.copper_runtime.clock.now() - iter_start;
+                        let elapsed = cu29::curuntime::perf_now(&self.copper_runtime.clock) - iter_start;
                         if elapsed < period {
                             std::thread::sleep(std::time::Duration::from_nanos(period.as_nanos() - elapsed.as_nanos()));
                         }
@@ -2492,11 +2492,11 @@ pub fn copper_runtime(args: TokenStream, input: TokenStream) -> TokenStream {
         } else {
             quote! {
                 loop  {
-                    let iter_start = self.copper_runtime.clock.now();
+                    let iter_start = cu29::curuntime::perf_now(&self.copper_runtime.clock);
                     let result = <Self as #app_trait<S, L>>::run_one_iteration(self, #sim_callback_arg);
                     if let Some(rate) = self.copper_runtime.runtime_config.rate_target_hz {
                         let period: CuDuration = (1_000_000_000u64 / rate).into();
-                        let elapsed = self.copper_runtime.clock.now() - iter_start;
+                        let elapsed = cu29::curuntime::perf_now(&self.copper_runtime.clock) - iter_start;
                         if elapsed < period {
                             busy_wait_for(period - elapsed);
                         }
@@ -4564,12 +4564,12 @@ fn generate_task_execution_tokens(
     let output_start_time = if output_ports.len() == 1 {
         quote! {
             if cumsg_output.metadata.process_time.start.is_none() {
-                cumsg_output.metadata.process_time.start = clock.now().into();
+                cumsg_output.metadata.process_time.start = cu29::curuntime::perf_now(clock).into();
             }
         }
     } else {
         quote! {
-            let start_time = clock.now().into();
+            let start_time = cu29::curuntime::perf_now(clock).into();
             #( if cumsg_output.#output_ports.metadata.process_time.start.is_none() {
                 cumsg_output.#output_ports.metadata.process_time.start = start_time;
             } )*
@@ -4578,12 +4578,12 @@ fn generate_task_execution_tokens(
     let output_end_time = if output_ports.len() == 1 {
         quote! {
             if cumsg_output.metadata.process_time.end.is_none() {
-                cumsg_output.metadata.process_time.end = clock.now().into();
+                cumsg_output.metadata.process_time.end = cu29::curuntime::perf_now(clock).into();
             }
         }
     } else {
         quote! {
-            let end_time = clock.now().into();
+            let end_time = cu29::curuntime::perf_now(clock).into();
             #( if cumsg_output.#output_ports.metadata.process_time.end.is_none() {
                 cumsg_output.#output_ports.metadata.process_time.end = end_time;
             } )*
@@ -5065,7 +5065,7 @@ fn generate_bridge_rx_execution_tokens(
                         step: CuComponentState::Process,
                         culistid: Some(clid),
                     });
-                    cumsg_output.metadata.process_time.start = clock.now().into();
+                    cumsg_output.metadata.process_time.start = cu29::curuntime::perf_now(clock).into();
                     let maybe_error = {
                         #rt_guard
                         ctx.clear_current_task();
@@ -5075,7 +5075,7 @@ fn generate_bridge_rx_execution_tokens(
                             cumsg_output,
                         )
                     };
-                    cumsg_output.metadata.process_time.end = clock.now().into();
+                    cumsg_output.metadata.process_time.end = cu29::curuntime::perf_now(clock).into();
                     if let Err(error) = maybe_error {
                         let decision = monitor.process_error(cu29::monitoring::ComponentId::new(#monitor_index), CuComponentState::Process, &error);
                         match decision {
@@ -5210,7 +5210,7 @@ fn generate_bridge_tx_execution_tokens(
                         step: CuComponentState::Process,
                         culistid: Some(clid),
                     });
-                    cumsg_output.metadata.process_time.start = clock.now().into();
+                    cumsg_output.metadata.process_time.start = cu29::curuntime::perf_now(clock).into();
                     let maybe_error = {
                         #rt_guard
                         ctx.clear_current_task();
@@ -5240,7 +5240,7 @@ fn generate_bridge_tx_execution_tokens(
                             }
                         }
                     }
-                    cumsg_output.metadata.process_time.end = clock.now().into();
+                    cumsg_output.metadata.process_time.end = cu29::curuntime::perf_now(clock).into();
                 }
             }
         },

core/cu29_runtime/Cargo.toml

@@ -90,6 +90,7 @@ defmt = ["cu29-log/defmt", "cu29-log-derive/defmt", "cu29-traits/defmt"]
 cuda = ["dep:cudarc"]
 macro_debug = []
 reflect = ["dep:bevy_reflect", "cu29-traits/reflect"]
+sysclock-perf = ["std"]
 remote-debug = [
   "std",
   "reflect",

core/cu29_runtime/src/curuntime.rs

@@ -64,6 +64,25 @@ pub struct CopperContext {
     pub clock: RobotClock,
 }
 
+/// Returns a monotonic instant used for local runtime performance timing.
+///
+/// When `sysclock-perf` (and `std`) are enabled this uses a process-local
+/// `RobotClock::new()` instance for timing. The returned value is a
+/// monotonically increasing duration since an unspecified origin (typically
+/// process or runtime initialization), not a wall-clock time-of-day. When
+/// `sysclock-perf` is disabled it delegates to the provided `RobotClock`.
+#[inline]
+pub fn perf_now(_clock: &RobotClock) -> CuTime {
+    #[cfg(all(feature = "std", feature = "sysclock-perf"))]
+    {
+        static PERF_CLOCK: std::sync::OnceLock<RobotClock> = std::sync::OnceLock::new();
+        return PERF_CLOCK.get_or_init(RobotClock::new).now();
+    }
+
+    #[allow(unreachable_code)]
+    _clock.now()
+}
+
 /// Manages the lifecycle of the copper lists and logging.
 pub struct CopperListsManager<P: CopperListTuple + Default, const NBCL: usize> {
     pub inner: CuListsManager<P, NBCL>,

examples/cu_flight_controller/Cargo.toml

@@ -169,6 +169,7 @@ default = ["sim"]
 sim_core = [
   "dep:cu29",
   "cu29/std",
+  "cu29/sysclock-perf",
   "dep:cu-ahrs",
   "dep:cu-crsf",
   "dep:cu-msp-bridge",

examples/cu_flight_controller/src/sim.rs

@@ -525,10 +525,11 @@ fn default_callback(_step: gnss::SimStep) -> SimOverride {
 }
 
 fn set_msg_timing<T: CuMsgPayload>(clock: &RobotClock, msg: &mut CuMsg<T>) {
-    let now = clock.now();
-    msg.tov = Tov::Time(now);
-    msg.metadata.process_time.start = now.into();
-    msg.metadata.process_time.end = now.into();
+    let tov = clock.now();
+    let perf = cu29::curuntime::perf_now(clock);
+    msg.tov = Tov::Time(tov);
+    msg.metadata.process_time.start = perf.into();
+    msg.metadata.process_time.end = perf.into();
 }
 
 fn axis_to_rc(value: f32) -> u16 {

examples/cu_rp_balancebot/Cargo.toml

@@ -114,6 +114,7 @@ sim = [
   "dep:bevy_anti_alias",
   "dep:avian3d",
   "dep:cached-path",
+  "cu29/sysclock-perf",
 ] # dependencies to run the Bevy-based balancebot sim
 bevymon = ["sim", "dep:cu-bevymon"]
 

examples/cu_rp_balancebot/src/sim_driver.rs

@@ -55,6 +55,20 @@ pub fn default_callback(step: crate::default::SimStep) -> SimOverride {
     }
 }
 
+fn set_msg_timing<T: CuMsgPayload>(clock: &RobotClock, msg: &mut CuMsg<T>) {
+    let tov = clock.now();
+    let perf = cu29::curuntime::perf_now(clock);
+    msg.tov = tov.into();
+    msg.metadata.process_time.start = perf.into();
+    msg.metadata.process_time.end = perf.into();
+}
+
+fn set_process_timing<T: CuMsgPayload>(clock: &RobotClock, msg: &mut CuMsg<T>) {
+    let perf = cu29::curuntime::perf_now(clock);
+    msg.metadata.process_time.start = perf.into();
+    msg.metadata.process_time.end = perf.into();
+}
+
 #[cfg(not(target_arch = "wasm32"))]
 #[cfg_attr(feature = "bevymon", allow(dead_code))]
 pub fn setup_native_copper(mut commands: Commands) {
@@ -228,11 +242,8 @@ pub fn run_copper_callback<T: Send + Sync + 'static>(
                 }
 
                 let analog_value = (angle_radians / (2.0 * std::f32::consts::PI) * 4096.0) as u16;
-                let now = clock.now();
                 output.set_payload(ADSReadingPayload { analog_value });
-                output.tov = now.into();
-                output.metadata.process_time.start = now.into();
-                output.metadata.process_time.end = now.into();
+                set_msg_timing(&clock, output);
                 SimOverride::ExecutedBySim
             }
             crate::default::SimStep::Balpos(_) => SimOverride::ExecutedBySim,
@@ -241,11 +252,8 @@ pub fn run_copper_callback<T: Send + Sync + 'static>(
                 let (cart_transform, _, _) =
                     bindings.single_mut().expect("Failed to get cart transform");
                 let ticks = (cart_transform.translation.x * 2000.0) as i32;
-                let now = clock.now();
                 output.set_payload(EncoderPayload { ticks });
-                output.tov = now.into();
-                output.metadata.process_time.start = now.into();
-                output.metadata.process_time.end = now.into();
+                set_msg_timing(&clock, output);
                 SimOverride::ExecutedBySim
             }
             crate::default::SimStep::Railpos(_) => SimOverride::ExecutedBySim,
@@ -255,7 +263,6 @@ pub fn run_copper_callback<T: Send + Sync + 'static>(
                     bindings.single_mut().expect("Failed to get cart force");
                 let maybe_motor_actuation = input.payload();
                 let override_motor = drag_state.override_motor;
-                let now = clock.now();
                 if override_motor {
                     if let Some(motor_actuation) = maybe_motor_actuation
                         && !motor_actuation.power.get::<ratio>().is_nan()
@@ -269,15 +276,13 @@ pub fn run_copper_callback<T: Send + Sync + 'static>(
                             .metadata
                             .set_status(format!("Applied force: {force_magnitude}"));
                     }
-                    output.metadata.process_time.start = now.into();
-                    output.metadata.process_time.end = now.into();
+                    set_process_timing(&clock, output);
                     return SimOverride::ExecutedBySim;
                 }
                 if let Some(motor_actuation) = maybe_motor_actuation {
                     if motor_actuation.power.get::<ratio>().is_nan() {
                         cart_force.0 = Vector::ZERO;
-                        output.metadata.process_time.start = now.into();
-                        output.metadata.process_time.end = now.into();
+                        set_process_timing(&clock, output);
                         return SimOverride::ExecutedBySim;
                     }
                     let total_mass = motor_model::total_mass_kg();
@@ -291,13 +296,11 @@ pub fn run_copper_callback<T: Send + Sync + 'static>(
                     output
                         .metadata
                         .set_status(format!("Applied force: {force_magnitude}"));
-                    output.metadata.process_time.start = now.into();
-                    output.metadata.process_time.end = now.into();
+                    set_process_timing(&clock, output);
                     SimOverride::ExecutedBySim
                 } else {
                     cart_force.0 = Vector::ZERO;
-                    output.metadata.process_time.start = now.into();
-                    output.metadata.process_time.end = now.into();
+                    set_process_timing(&clock, output);
                     SimOverride::Errored("Safety Mode.".into())
                 }
             }