benchmark: add new methods b.record_measure/1 and b.all_recorded_measures/0 (#19561)

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()

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')
+}