diff --git a/vlib/benchmark/benchmark.v b/vlib/benchmark/benchmark.v index cc5749afb2..a8cd2f40ea 100644 --- a/vlib/benchmark/benchmark.v +++ b/vlib/benchmark/benchmark.v @@ -25,6 +25,7 @@ pub mut: cstep int bok string bfail string + measured_steps []string } // new_benchmark returns a `Benchmark` instance on the stack. @@ -128,6 +129,19 @@ pub fn (mut b Benchmark) measure(label string) i64 { return res } +// record_measure stores the current time doing `label`, since the benchmark +// was started, or since the last call to `b.record_measure`. +// It is similar to `b.measure`, but unlike it, will not print the measurement +// immediately, just record it for later. You can call `b.all_recorded_measures` +// to retrieve all measures stored by `b.record_measure` calls. +pub fn (mut b Benchmark) record_measure(label string) i64 { + b.ok() + res := b.step_timer.elapsed().microseconds() + b.measured_steps << b.step_message_with_label(benchmark.b_spent, 'in ${label}') + b.step() + return res +} + // step_message_with_label_and_duration returns a string describing the current step. pub fn (b &Benchmark) step_message_with_label_and_duration(label string, msg string, sduration time.Duration) string { timed_line := b.tdiff_in_ms(msg, sduration.microseconds()) @@ -213,6 +227,12 @@ pub fn (b &Benchmark) total_message(msg string) string { return tmsg } +// all_recorded_measures returns a string, that contains all the recorded +// measure messages, done by individual calls to `b.record_measure`. +pub fn (b &Benchmark) all_recorded_measures() string { + return b.measured_steps.join_lines() +} + // total_duration returns the duration in ms. pub fn (b &Benchmark) total_duration() i64 { return b.bench_timer.elapsed().milliseconds() diff --git a/vlib/benchmark/benchmark_test.v b/vlib/benchmark/benchmark_test.v new file mode 100644 index 0000000000..37e92a6dbd --- /dev/null +++ b/vlib/benchmark/benchmark_test.v @@ -0,0 +1,38 @@ +import time +import benchmark + +fn test_measure() { + mut b := benchmark.start() + time.sleep(200 * time.millisecond) + x := b.measure('sleeping') // returns microseconds + flush_stdout() + assert x > 150_000 + // assert x < 800_000 // this can be much longer on a slow CI runner +} + +fn test_record_measure() { + mut b := benchmark.start() + println('step 1') + flush_stdout() + time.sleep(100 * time.millisecond) + x := b.record_measure('sleeping 1') + assert x > 50_000 + // assert x < 200_000 + flush_stdout() + // + println('step 2') + flush_stdout() + time.sleep(150 * time.millisecond) + y := b.record_measure('sleeping 2') + assert y > 100_000 + // assert y < 200_000 + flush_stdout() + // + res := b.all_recorded_measures() + println('All recorded measurements:') + println(res) + flush_stdout() + assert res.contains('ms in sleeping 1') + assert res.contains('ms in sleeping 1') + assert res.contains('SPENT') +}