v / vlib / benchmark / benchmark.v
287 lines · 255 sloc · 8.88 KB · 7ed9ee2992ef15789d82ab961f525d9bb2885204
Raw
1module benchmark
2
3import time
4import term
5import arrays
6
7const step_label_width = 5
8
9pub const b_ok = term.ok_message('OK ')
10pub const b_fail = term.fail_message('FAIL')
11pub const b_skip = term.warn_message('SKIP')
12pub const b_spent = term.ok_message('SPENT')
13
14pub struct Benchmark {
15pub mut:
16 bench_timer time.StopWatch
17 verbose bool
18 no_cstep bool
19 step_timer time.StopWatch
20 ntotal int
21 nok int
22 nfail int
23 nskip int
24 nexpected_steps int
25 njobs int
26 cstep int
27 bok string
28 bfail string
29 measured_steps []string
30 step_data map[string][]f64
31}
32
33// new_benchmark returns a `Benchmark` instance on the stack.
34pub fn new_benchmark() Benchmark {
35 return Benchmark{
36 bench_timer: time.new_stopwatch()
37 verbose: true
38 }
39}
40
41// new_benchmark_no_cstep returns a new `Benchmark` instance with step counting disabled.
42pub fn new_benchmark_no_cstep() Benchmark {
43 return Benchmark{
44 bench_timer: time.new_stopwatch()
45 verbose: true
46 no_cstep: true
47 }
48}
49
50// new_benchmark_pointer returns a new `Benchmark` instance allocated on the heap.
51// This is useful for long-lived use of `Benchmark` instances.
52pub fn new_benchmark_pointer() &Benchmark {
53 return &Benchmark{
54 bench_timer: time.new_stopwatch()
55 verbose: true
56 }
57}
58
59// set_total_expected_steps sets the total amount of steps the benchmark is expected to take.
60pub fn (mut b Benchmark) set_total_expected_steps(n int) {
61 b.nexpected_steps = n
62}
63
64// stop stops the internal benchmark timer.
65pub fn (mut b Benchmark) stop() {
66 b.bench_timer.stop()
67}
68
69// step increases the step count by 1 and restarts the internal timer.
70pub fn (mut b Benchmark) step() {
71 b.step_timer.restart()
72 if !b.no_cstep {
73 b.cstep++
74 }
75}
76
77// step_restart will restart the internal step timer.
78// Note that the step count will *stay the same*.
79// This method is useful, when you want to do some optional preparation
80// after you have called .step(), so that the time for that optional
81// preparation will *not* be added to the duration of the step.
82pub fn (mut b Benchmark) step_restart() {
83 b.step_timer.restart()
84}
85
86// fail increases the fail count by 1 and stops the internal timer.
87pub fn (mut b Benchmark) fail() {
88 b.step_timer.stop()
89 b.ntotal++
90 b.nfail++
91}
92
93// ok increases the ok count by 1 and stops the internal timer.
94pub fn (mut b Benchmark) ok() {
95 b.step_timer.stop()
96 b.ntotal++
97 b.nok++
98}
99
100// skip increases the skip count by 1 and stops the internal timer.
101pub fn (mut b Benchmark) skip() {
102 b.step_timer.stop()
103 b.ntotal++
104 b.nskip++
105}
106
107// fail_many increases the fail count by `n` and stops the internal timer.
108pub fn (mut b Benchmark) fail_many(n int) {
109 b.step_timer.stop()
110 b.ntotal += n
111 b.nfail += n
112}
113
114// ok_many increases the ok count by `n` and stops the internal timer.
115pub fn (mut b Benchmark) ok_many(n int) {
116 b.step_timer.stop()
117 b.ntotal += n
118 b.nok += n
119}
120
121// neither_fail_nor_ok stops the internal timer.
122pub fn (mut b Benchmark) neither_fail_nor_ok() {
123 b.step_timer.stop()
124}
125
126// start returns a new, running, instance of `Benchmark`.
127// This is a shorthand for calling `new_benchmark().step()`.
128pub fn start() Benchmark {
129 mut b := new_benchmark()
130 b.step()
131 return b
132}
133
134// measure prints the current time spent doing `label`, since the benchmark was started, or since its last call.
135pub fn (mut b Benchmark) measure(label string) i64 {
136 b.ok()
137 res := b.step_timer.elapsed().microseconds()
138 println(b.step_message_with_label(b_spent, 'in ${label}'))
139 b.step()
140 return res
141}
142
143// record_measure stores the current time doing `label`, since the benchmark was started, or since the last call to `b.record_measure`.
144// It is similar to `b.measure`, but unlike it, will not print the measurement
145// immediately, just record it for later. You can call `b.all_recorded_measures`
146// to retrieve all measures stored by `b.record_measure` calls.
147pub fn (mut b Benchmark) record_measure(label string) i64 {
148 b.ok()
149 res := b.step_timer.elapsed().microseconds()
150 b.measured_steps << b.step_message_with_label(b_spent, 'in ${label}')
151 if label !in b.step_data {
152 b.step_data[label] = []f64{}
153 }
154 b.step_data[label] << f64(res)
155 b.step()
156 return res
157}
158
159// MessageOptions allows passing an optional preparation time too to each label method.
160// If it is set, the preparation time (compile time) will be shown before the measured runtime.
161@[params]
162pub struct MessageOptions {
163pub:
164 preparation time.Duration // the duration of the preparation time for the step
165}
166
167// step_message_with_label_and_duration returns a string describing the current step.
168pub fn (b &Benchmark) step_message_with_label_and_duration(label string, msg string, sduration time.Duration,
169 opts MessageOptions) string {
170 timed_line := b.tdiff_in_ms(msg, sduration.microseconds())
171 flabel := format_step_label(label)
172 if b.nexpected_steps > 1 {
173 mut sprogress := ''
174 if b.nexpected_steps < 10 {
175 sprogress = if b.no_cstep {
176 'TMP1/${b.nexpected_steps:1d}'
177 } else {
178 '${b.cstep:1d}/${b.nexpected_steps:1d}'
179 }
180 } else if b.nexpected_steps >= 10 && b.nexpected_steps < 100 {
181 sprogress = if b.no_cstep {
182 'TMP2/${b.nexpected_steps:2d}'
183 } else {
184 '${b.cstep:2d}/${b.nexpected_steps:2d}'
185 }
186 } else if b.nexpected_steps >= 100 && b.nexpected_steps < 1000 {
187 sprogress = if b.no_cstep {
188 'TMP3/${b.nexpected_steps:3d}'
189 } else {
190 '${b.cstep:3d}/${b.nexpected_steps:3d}'
191 }
192 } else {
193 sprogress = if b.no_cstep {
194 'TMP4/${b.nexpected_steps:4d}'
195 } else {
196 '${b.cstep:4d}/${b.nexpected_steps:4d}'
197 }
198 }
199 if opts.preparation > 0 {
200 return '${flabel} [${sprogress}] C: ${f64(opts.preparation.microseconds()) / 1_000.0:7.1F} ms, R: ${timed_line}'
201 }
202 return '${flabel} [${sprogress}] ${timed_line}'
203 }
204 return '${flabel}${timed_line}'
205}
206
207fn format_step_label(label string) string {
208 visible_len := term.strip_ansi(label).len
209 if visible_len >= step_label_width {
210 return label
211 }
212 return label + ' '.repeat(step_label_width - visible_len)
213}
214
215// step_message_with_label returns a string describing the current step using current time as duration.
216pub fn (b &Benchmark) step_message_with_label(label string, msg string, opts MessageOptions) string {
217 return b.step_message_with_label_and_duration(label, msg, b.step_timer.elapsed(), opts)
218}
219
220// step_message returns a string describing the current step.
221pub fn (b &Benchmark) step_message(msg string, opts MessageOptions) string {
222 return b.step_message_with_label('', msg, opts)
223}
224
225// step_message_ok returns a string describing the current step with an standard "OK" label.
226pub fn (b &Benchmark) step_message_ok(msg string, opts MessageOptions) string {
227 return b.step_message_with_label(b_ok, msg, opts)
228}
229
230// step_message_fail returns a string describing the current step with an standard "FAIL" label.
231pub fn (b &Benchmark) step_message_fail(msg string, opts MessageOptions) string {
232 return b.step_message_with_label(b_fail, msg, opts)
233}
234
235// step_message_skip returns a string describing the current step with an standard "SKIP" label.
236pub fn (b &Benchmark) step_message_skip(msg string, opts MessageOptions) string {
237 return b.step_message_with_label(b_skip, msg, opts)
238}
239
240// total_message returns a string with total summary of the benchmark run.
241pub fn (b &Benchmark) total_message(msg string) string {
242 the_label := term.colorize(term.gray, msg)
243 mut tmsg := term.colorize(term.bold, 'Summary for ${the_label}:') + ' '
244 if b.nfail > 0 {
245 tmsg += term.colorize(term.bold, term.colorize(term.red, '${b.nfail} failed')) + ', '
246 }
247 if b.nok > 0 {
248 tmsg += term.colorize(term.bold, term.colorize(term.green, '${b.nok} passed')) + ', '
249 }
250 if b.nskip > 0 {
251 tmsg += term.colorize(term.bold, term.colorize(term.yellow, '${b.nskip} skipped')) + ', '
252 }
253 mut njobs_label := ''
254 if b.njobs > 0 {
255 if b.njobs == 1 {
256 njobs_label = ', on ${term.colorize(term.bold, 1.str())} job'
257 } else {
258 njobs_label = ', on ${term.colorize(term.bold, b.njobs.str())} parallel jobs'
259 }
260 }
261 tmsg += '${b.ntotal} total. ${term.colorize(term.bold, 'Elapsed time:')} ${b.bench_timer.elapsed().microseconds() / 1000} ms${njobs_label}.'
262 if msg in b.step_data && b.step_data[msg].len > 1 {
263 min := arrays.min(b.step_data[msg]) or { 0 } / 1000.0
264 max := arrays.max(b.step_data[msg]) or { 0 } / 1000.0
265 avg := (arrays.sum(b.step_data[msg]) or { 0 } / b.step_data[msg].len) / 1000.0
266 tmsg += ' Min: ${min:.3f} ms. Max: ${max:.3f} ms. Avg: ${avg:.3f} ms'
267 }
268 return tmsg
269}
270
271// all_recorded_measures returns a string, that contains all the recorded measure messages, done by individual calls to `b.record_measure`.
272pub fn (b &Benchmark) all_recorded_measures() string {
273 return b.measured_steps.join_lines()
274}
275
276// total_duration returns the duration in ms.
277pub fn (b &Benchmark) total_duration() i64 {
278 return b.bench_timer.elapsed().milliseconds()
279}
280
281// tdiff_in_ms prefixes `s` with a time difference calculation.
282fn (b &Benchmark) tdiff_in_ms(s string, tdiff i64) string {
283 if b.verbose {
284 return '${f64(tdiff) / 1000.0:9.3f} ms ${s}'
285 }
286 return s
287}
288