runmat_runtime/builtins/timing/
timeit.rs

1//! MATLAB-compatible `timeit` builtin for RunMat.
2//!
3//! Measures the execution time of zero-input function handles by running them
4//! repeatedly and returning the median per-invocation runtime in seconds.
5
6use std::cmp::Ordering;
7use std::time::Instant;
8
9use runmat_builtins::Value;
10use runmat_macros::runtime_builtin;
11
12use crate::builtins::common::spec::{
13    BroadcastSemantics, BuiltinFusionSpec, BuiltinGpuSpec, ConstantStrategy, GpuOpKind,
14    ReductionNaN, ResidencyPolicy, ShapeRequirements,
15};
16#[cfg(feature = "doc_export")]
17use crate::register_builtin_doc_text;
18use crate::{register_builtin_fusion_spec, register_builtin_gpu_spec};
19
20const TARGET_BATCH_SECONDS: f64 = 0.005;
21const MAX_BATCH_SECONDS: f64 = 0.25;
22const LOOP_COUNT_LIMIT: usize = 1 << 20;
23const MIN_SAMPLE_COUNT: usize = 7;
24const MAX_SAMPLE_COUNT: usize = 21;
25
26#[cfg(feature = "doc_export")]
27pub const DOC_MD: &str = r#"---
28title: "timeit"
29category: "timing"
30keywords: ["timeit", "benchmark", "timing", "performance", "gpu"]
31summary: "Measure the execution time of a zero-argument function handle."
32references: []
33gpu_support:
34  elementwise: false
35  reduction: false
36  precisions: []
37  broadcasting: "none"
38  notes: "Runs purely on the host CPU; GPU work inside the timed function executes through the active provider."
39fusion:
40  elementwise: false
41  reduction: false
42  max_inputs: 0
43  constants: "inline"
44requires_feature: null
45tested:
46  unit: "builtins::timing::timeit::tests"
47  integration: "builtins::timing::timeit::tests::timeit_measures_time"
48---
49
50# Measure execution time of a function handle
51`t = timeit(f)` evaluates the zero-argument function handle `f` repeatedly and returns the median runtime (in seconds).
52RunMat accepts the optional `numOutputs` argument for MATLAB compatibility; today the handle executes with its default output arity (or none when you pass `0`) and all returned values are discarded.
53
54## Syntax
55```matlab
56t = timeit(f)
57t = timeit(f, numOutputs)
58```
59
60- `f` is a zero-argument function handle (for example, `@() myOp(A)`).
61- `numOutputs` is an optional nonnegative integer kept for MATLAB compatibility. Passing `0` suppresses outputs entirely; any other value currently executes the handle with its default output arity while discarding the result.
62
63## How `timeit` works
64- Executes `f` repeatedly, adjusting the inner loop count until a single batch takes at least a few milliseconds or the function is slow enough.
65- Collects multiple samples (at least seven batches) and returns the median per-invocation time, which is robust against outliers.
66- Drops the outputs produced by `f`; you should perform any validation that depends on those outputs inside the handle. Multi-output dispatch will route through this helper once the runtime exposes multi-return `feval`.
67- Leaves GPU residency untouched—if `f` launches GPU kernels, they execute on the active provider. Insert `wait(gpuDevice)` inside the handle if you need explicit synchronisation.
68
69## Examples
70
71### Timing a simple anonymous function
72```matlab
73f = @() sin(rand(1000, 1));
74t = timeit(f);
75```
76
77### Comparing two implementations
78```matlab
79A = rand(1e5, 1);
80slow = @() sum(A .* A);
81fast = @() sumsq(A);
82
83slowTime = timeit(slow);
84fastTime = timeit(fast);
85```
86
87### Timing a function that returns no outputs
88```matlab
89logMessage = @() fprintf("Iteration complete\n");
90t = timeit(logMessage, 0);
91```
92
93### Timing a multiple-output function
94```matlab
95svdTime = timeit(@() svd(rand(256)), 3);
96```
97This records the runtime while discarding any outputs produced by `svd`.
98
99### Measuring GPU-bound work
100```matlab
101gfun = @() gather(sin(gpuArray.rand(4096, 1)));
102tgpu = timeit(gfun);
103```
104
105### Timing a preallocation helper
106```matlab
107makeMatrix = @() zeros(2048, 2048);
108t = timeit(makeMatrix);
109```
110
111## FAQ
112
1131. **What does `timeit` return?** — A scalar double containing the median runtime per invocation in seconds.
1142. **How many runs does `timeit` perform?** — It automatically selects a loop count so each batch lasts a few milliseconds, collecting at least seven batches.
1153. **Does `timeit` synchronise GPU kernels?** — No. Insert `wait(gpuDevice)` inside the handle when you need explicit synchronisation.
1164. **Can I time functions that require inputs?** — Yes. Capture them in the handle, for example `timeit(@() myfun(A, B))`.
1175. **How do I time a function with multiple outputs?** — Pass `timeit(@() svd(A), 3)` to mirror MATLAB’s call signature. RunMat currently ignores values greater than zero until multi-output dispatch lands, but the handle still executes.
1186. **Why do successive runs differ slightly?** — Normal system jitter, cache effects, and GPU scheduling can change runtimes slightly; the median mitigates outliers.
1197. **Can `timeit` time scripts?** — Wrap the script body in a function handle so it becomes zero-argument, then call `timeit` on that handle.
1208. **Does `timeit` participate in fusion or JIT tiers?** — It simply executes the provided handle; any tiering or fusion happens inside the timed function.
1219. **What happens if the function errors?** — The error is propagated immediately and timing stops, matching MATLAB behaviour.
12210. **Is there a limit on runs?** — Yes. `timeit` caps the inner loop at about one million iterations to avoid runaway measurements.
123
124## See Also
125[tic](./tic), [toc](./toc), [feval](../introspection/feval)
126
127## Source & Feedback
128- Implementation: [`crates/runmat-runtime/src/builtins/timing/timeit.rs`](https://github.com/runmat-org/runmat/blob/main/crates/runmat-runtime/src/builtins/timing/timeit.rs)
129- Found a behavioural difference? [Open an issue](https://github.com/runmat-org/runmat/issues/new/choose) with a minimal repro.
130"#;
131
132pub const GPU_SPEC: BuiltinGpuSpec = BuiltinGpuSpec {
133    name: "timeit",
134    op_kind: GpuOpKind::Custom("timer"),
135    supported_precisions: &[],
136    broadcast: BroadcastSemantics::None,
137    provider_hooks: &[],
138    constant_strategy: ConstantStrategy::InlineLiteral,
139    residency: ResidencyPolicy::GatherImmediately,
140    nan_mode: ReductionNaN::Include,
141    two_pass_threshold: None,
142    workgroup_size: None,
143    accepts_nan_mode: false,
144    notes: "Host-side helper; GPU kernels execute only if invoked by the timed function.",
145};
146
147register_builtin_gpu_spec!(GPU_SPEC);
148
149pub const FUSION_SPEC: BuiltinFusionSpec = BuiltinFusionSpec {
150    name: "timeit",
151    shape: ShapeRequirements::Any,
152    constant_strategy: ConstantStrategy::InlineLiteral,
153    elementwise: None,
154    reduction: None,
155    emits_nan: false,
156    notes: "Timing helper; excluded from fusion planning.",
157};
158
159register_builtin_fusion_spec!(FUSION_SPEC);
160
161#[cfg(feature = "doc_export")]
162register_builtin_doc_text!("timeit", DOC_MD);
163
164#[runtime_builtin(
165    name = "timeit",
166    category = "timing",
167    summary = "Measure the execution time of a zero-argument function handle.",
168    keywords = "timeit,benchmark,timing,performance,gpu",
169    accel = "helper"
170)]
171fn timeit_builtin(func: Value, rest: Vec<Value>) -> Result<Value, String> {
172    let requested_outputs = parse_num_outputs(&rest)?;
173    let callable = prepare_callable(func, requested_outputs)?;
174
175    // Warm-up once to catch early errors and pay one-time JIT costs.
176    callable.invoke()?;
177
178    let loop_count = determine_loop_count(&callable)?;
179    let samples = collect_samples(&callable, loop_count)?;
180    if samples.is_empty() {
181        return Ok(Value::Num(0.0));
182    }
183
184    Ok(Value::Num(compute_median(samples)))
185}
186
187fn parse_num_outputs(rest: &[Value]) -> Result<Option<usize>, String> {
188    match rest.len() {
189        0 => Ok(None),
190        1 => parse_non_negative_integer(&rest[0]).map(Some),
191        _ => Err("timeit: too many input arguments".to_string()),
192    }
193}
194
195fn parse_non_negative_integer(value: &Value) -> Result<usize, String> {
196    match value {
197        Value::Int(iv) => {
198            let raw = iv.to_i64();
199            if raw < 0 {
200                Err("timeit: numOutputs must be a nonnegative integer".to_string())
201            } else {
202                Ok(raw as usize)
203            }
204        }
205        Value::Num(n) => {
206            if !n.is_finite() {
207                return Err("timeit: numOutputs must be finite".to_string());
208            }
209            if *n < 0.0 {
210                return Err("timeit: numOutputs must be a nonnegative integer".to_string());
211            }
212            let rounded = n.round();
213            if (rounded - n).abs() > f64::EPSILON {
214                return Err("timeit: numOutputs must be an integer value".to_string());
215            }
216            Ok(rounded as usize)
217        }
218        _ => Err("timeit: numOutputs must be a scalar numeric value".to_string()),
219    }
220}
221
222fn determine_loop_count(callable: &TimeitCallable) -> Result<usize, String> {
223    let mut loops = 1usize;
224    loop {
225        let elapsed = run_batch(callable, loops)?;
226        if elapsed >= TARGET_BATCH_SECONDS
227            || elapsed >= MAX_BATCH_SECONDS
228            || loops >= LOOP_COUNT_LIMIT
229        {
230            return Ok(loops);
231        }
232        loops = loops.saturating_mul(2);
233        if loops == 0 {
234            return Ok(LOOP_COUNT_LIMIT);
235        }
236    }
237}
238
239fn collect_samples(callable: &TimeitCallable, loop_count: usize) -> Result<Vec<f64>, String> {
240    let mut samples = Vec::with_capacity(MIN_SAMPLE_COUNT);
241    while samples.len() < MIN_SAMPLE_COUNT {
242        let elapsed = run_batch(callable, loop_count)?;
243        let per_iter = elapsed / loop_count as f64;
244        samples.push(per_iter);
245        if samples.len() >= MAX_SAMPLE_COUNT || elapsed >= MAX_BATCH_SECONDS {
246            break;
247        }
248    }
249    Ok(samples)
250}
251
252fn run_batch(callable: &TimeitCallable, loop_count: usize) -> Result<f64, String> {
253    let start = Instant::now();
254    for _ in 0..loop_count {
255        let value = callable.invoke()?;
256        drop(value);
257    }
258    Ok(start.elapsed().as_secs_f64())
259}
260
261fn compute_median(mut samples: Vec<f64>) -> f64 {
262    if samples.is_empty() {
263        return 0.0;
264    }
265    samples.sort_by(|a, b| match (a.is_nan(), b.is_nan()) {
266        (true, true) => Ordering::Equal,
267        (true, false) => Ordering::Greater,
268        (false, true) => Ordering::Less,
269        (false, false) => a.partial_cmp(b).unwrap_or_else(|| {
270            if a < b {
271                Ordering::Less
272            } else {
273                Ordering::Greater
274            }
275        }),
276    });
277    let mid = samples.len() / 2;
278    if samples.len() % 2 == 1 {
279        samples[mid]
280    } else {
281        (samples[mid - 1] + samples[mid]) * 0.5
282    }
283}
284
285#[derive(Clone)]
286struct TimeitCallable {
287    handle: Value,
288    num_outputs: Option<usize>,
289}
290
291impl TimeitCallable {
292    fn invoke(&self) -> Result<Value, String> {
293        // The runtime currently treats all builtin invocations as returning a single `Value`.
294        // The optional `num_outputs` flag is stored so future multi-output support can
295        // request the correct number of outputs when dispatching through `feval`.
296        // For now, we invoke the handle normally and drop whatever value is produced.
297        if let Some(0) = self.num_outputs {
298            let value = crate::call_builtin("feval", std::slice::from_ref(&self.handle))?;
299            drop(value);
300            Ok(Value::Num(0.0))
301        } else {
302            crate::call_builtin("feval", std::slice::from_ref(&self.handle))
303        }
304    }
305}
306
307fn prepare_callable(func: Value, num_outputs: Option<usize>) -> Result<TimeitCallable, String> {
308    match func {
309        Value::String(text) => parse_handle_string(&text).map(|handle| TimeitCallable {
310            handle: Value::String(handle),
311            num_outputs,
312        }),
313        Value::CharArray(arr) => {
314            if arr.rows != 1 {
315                Err(
316                    "timeit: function handle must be a string scalar or function handle"
317                        .to_string(),
318                )
319            } else {
320                let text: String = arr.data.iter().collect();
321                parse_handle_string(&text).map(|handle| TimeitCallable {
322                    handle: Value::String(handle),
323                    num_outputs,
324                })
325            }
326        }
327        Value::StringArray(sa) => {
328            if sa.data.len() == 1 {
329                parse_handle_string(&sa.data[0]).map(|handle| TimeitCallable {
330                    handle: Value::String(handle),
331                    num_outputs,
332                })
333            } else {
334                Err(
335                    "timeit: function handle must be a string scalar or function handle"
336                        .to_string(),
337                )
338            }
339        }
340        Value::FunctionHandle(name) => Ok(TimeitCallable {
341            handle: Value::String(format!("@{name}")),
342            num_outputs,
343        }),
344        Value::Closure(closure) => Ok(TimeitCallable {
345            handle: Value::Closure(closure),
346            num_outputs,
347        }),
348        other => Err(format!(
349            "timeit: first argument must be a function handle, got {other:?}"
350        )),
351    }
352}
353
354fn parse_handle_string(text: &str) -> Result<String, String> {
355    let trimmed = text.trim();
356    if let Some(rest) = trimmed.strip_prefix('@') {
357        if rest.trim().is_empty() {
358            Err("timeit: empty function handle string".to_string())
359        } else {
360            Ok(format!("@{}", rest.trim()))
361        }
362    } else {
363        Err("timeit: expected a function handle string beginning with '@'".to_string())
364    }
365}
366
367#[cfg(test)]
368mod tests {
369    use super::*;
370    use runmat_builtins::IntValue;
371    use std::sync::atomic::{AtomicUsize, Ordering};
372
373    #[cfg(feature = "doc_export")]
374    use crate::builtins::common::test_support;
375
376    static COUNTER_DEFAULT: AtomicUsize = AtomicUsize::new(0);
377    static COUNTER_NUM_OUTPUTS: AtomicUsize = AtomicUsize::new(0);
378    static COUNTER_INVALID: AtomicUsize = AtomicUsize::new(0);
379    static COUNTER_ZERO_OUTPUTS: AtomicUsize = AtomicUsize::new(0);
380
381    #[runtime_builtin(name = "__timeit_helper_counter_default")]
382    fn helper_counter_default() -> Result<Value, String> {
383        COUNTER_DEFAULT.fetch_add(1, Ordering::SeqCst);
384        Ok(Value::Num(1.0))
385    }
386
387    #[runtime_builtin(name = "__timeit_helper_counter_outputs")]
388    fn helper_counter_outputs() -> Result<Value, String> {
389        COUNTER_NUM_OUTPUTS.fetch_add(1, Ordering::SeqCst);
390        Ok(Value::Num(1.0))
391    }
392
393    #[runtime_builtin(name = "__timeit_helper_counter_invalid")]
394    fn helper_counter_invalid() -> Result<Value, String> {
395        COUNTER_INVALID.fetch_add(1, Ordering::SeqCst);
396        Ok(Value::Num(1.0))
397    }
398
399    #[runtime_builtin(name = "__timeit_helper_zero_outputs")]
400    fn helper_counter_zero_outputs() -> Result<Value, String> {
401        COUNTER_ZERO_OUTPUTS.fetch_add(1, Ordering::SeqCst);
402        Ok(Value::Num(0.0))
403    }
404
405    fn default_handle() -> Value {
406        Value::String("@__timeit_helper_counter_default".to_string())
407    }
408
409    fn outputs_handle() -> Value {
410        Value::String("@__timeit_helper_counter_outputs".to_string())
411    }
412
413    fn invalid_handle() -> Value {
414        Value::String("@__timeit_helper_counter_invalid".to_string())
415    }
416
417    fn zero_outputs_handle() -> Value {
418        Value::String("@__timeit_helper_zero_outputs".to_string())
419    }
420
421    #[test]
422    fn timeit_measures_time() {
423        COUNTER_DEFAULT.store(0, Ordering::SeqCst);
424        let result = timeit_builtin(default_handle(), Vec::new()).expect("timeit");
425        match result {
426            Value::Num(v) => assert!(v >= 0.0),
427            other => panic!("expected numeric result, got {other:?}"),
428        }
429        assert!(
430            COUNTER_DEFAULT.load(Ordering::SeqCst) >= MIN_SAMPLE_COUNT,
431            "expected at least {} invocations",
432            MIN_SAMPLE_COUNT
433        );
434    }
435
436    #[test]
437    fn timeit_accepts_num_outputs_argument() {
438        COUNTER_NUM_OUTPUTS.store(0, Ordering::SeqCst);
439        let args = vec![Value::Int(IntValue::I32(3))];
440        let _ = timeit_builtin(outputs_handle(), args).expect("timeit numOutputs");
441        assert!(
442            COUNTER_NUM_OUTPUTS.load(Ordering::SeqCst) >= MIN_SAMPLE_COUNT,
443            "expected at least {} invocations",
444            MIN_SAMPLE_COUNT
445        );
446    }
447
448    #[test]
449    fn timeit_supports_zero_outputs() {
450        COUNTER_ZERO_OUTPUTS.store(0, Ordering::SeqCst);
451        let args = vec![Value::Int(IntValue::I32(0))];
452        let _ = timeit_builtin(zero_outputs_handle(), args).expect("timeit zero outputs");
453        assert!(
454            COUNTER_ZERO_OUTPUTS.load(Ordering::SeqCst) >= MIN_SAMPLE_COUNT,
455            "expected at least {} invocations",
456            MIN_SAMPLE_COUNT
457        );
458    }
459
460    #[test]
461    #[cfg(feature = "wgpu")]
462    fn timeit_runs_with_wgpu_provider_registered() {
463        let _ = runmat_accelerate::backend::wgpu::provider::register_wgpu_provider(
464            runmat_accelerate::backend::wgpu::provider::WgpuProviderOptions::default(),
465        );
466        let result = timeit_builtin(default_handle(), Vec::new()).expect("timeit with wgpu");
467        match result {
468            Value::Num(v) => assert!(v >= 0.0),
469            other => panic!("expected numeric result, got {other:?}"),
470        }
471    }
472
473    #[test]
474    fn timeit_rejects_non_function_input() {
475        let err = timeit_builtin(Value::Num(1.0), Vec::new()).unwrap_err();
476        assert!(
477            err.to_ascii_lowercase().contains("function"),
478            "unexpected error text: {err}"
479        );
480    }
481
482    #[test]
483    fn timeit_rejects_invalid_num_outputs() {
484        COUNTER_INVALID.store(0, Ordering::SeqCst);
485        let err = timeit_builtin(invalid_handle(), vec![Value::Num(-1.0)]).unwrap_err();
486        assert!(err.to_ascii_lowercase().contains("nonnegative"));
487        assert_eq!(COUNTER_INVALID.load(Ordering::SeqCst), 0);
488    }
489
490    #[test]
491    fn timeit_rejects_extra_arguments() {
492        let err =
493            timeit_builtin(default_handle(), vec![Value::from(1.0), Value::from(2.0)]).unwrap_err();
494        assert!(err.to_ascii_lowercase().contains("too many"));
495    }
496
497    #[test]
498    #[cfg(feature = "doc_export")]
499    fn doc_examples_present() {
500        let blocks = test_support::doc_examples(DOC_MD);
501        assert!(!blocks.is_empty());
502    }
503}
runmat_runtime/builtins/timing/timeit.rs

runmat_runtime/builtins/timing/
timeit.rs
