1 | module main |
2 | |
3 | import os |
4 | import flag |
5 | import time |
6 | import term |
7 | import math |
8 | import scripting |
9 | |
10 | struct CmdResult { |
11 | mut: |
12 | runs int |
13 | cmd string |
14 | icmd int |
15 | outputs []string |
16 | oms map[string][]int |
17 | summary map[string]Aints |
18 | timings []int |
19 | atiming Aints |
20 | } |
21 | |
22 | struct Context { |
23 | mut: |
24 | count int |
25 | series int |
26 | warmup int |
27 | show_help bool |
28 | show_output bool |
29 | use_newline bool // use \n instead of \r, so the last line is not overwritten |
30 | fail_on_regress_percent int |
31 | fail_on_maxtime int // in ms |
32 | verbose bool |
33 | commands []string |
34 | results []CmdResult |
35 | cmd_template string // {T} will be substituted with the current command |
36 | cmd_params map[string][]string |
37 | cline string // a terminal clearing line |
38 | cgoback string |
39 | nmins int // number of minimums to discard |
40 | nmaxs int // number of maximums to discard |
41 | } |
42 | |
43 | [unsafe] |
44 | fn (mut result CmdResult) free() { |
45 | unsafe { |
46 | result.cmd.free() |
47 | result.outputs.free() |
48 | result.oms.free() |
49 | result.summary.free() |
50 | result.timings.free() |
51 | result.atiming.free() |
52 | } |
53 | } |
54 | |
55 | [unsafe] |
56 | fn (mut context Context) free() { |
57 | unsafe { |
58 | context.commands.free() |
59 | context.results.free() |
60 | context.cmd_template.free() |
61 | context.cmd_params.free() |
62 | context.cline.free() |
63 | context.cgoback.free() |
64 | } |
65 | } |
66 | |
67 | struct Aints { |
68 | values []int |
69 | mut: |
70 | imin int |
71 | imax int |
72 | average f64 |
73 | stddev f64 |
74 | nmins int // number of discarded fastest results |
75 | nmaxs int // number of discarded slowest results |
76 | } |
77 | |
78 | [unsafe] |
79 | fn (mut a Aints) free() { |
80 | unsafe { a.values.free() } |
81 | } |
82 | |
83 | fn new_aints(ovals []int, extreme_mins int, extreme_maxs int) Aints { |
84 | mut res := Aints{ |
85 | values: ovals // remember the original values |
86 | nmins: extreme_mins |
87 | nmaxs: extreme_maxs |
88 | } |
89 | mut sum := i64(0) |
90 | mut imin := math.max_i32 |
91 | mut imax := -math.max_i32 |
92 | // discard the extremes: |
93 | mut vals := []int{} |
94 | for x in ovals { |
95 | vals << x |
96 | } |
97 | vals.sort() |
98 | if vals.len > extreme_mins + extreme_maxs { |
99 | vals = vals[extreme_mins..vals.len - extreme_maxs].clone() |
100 | } else { |
101 | vals = [] |
102 | } |
103 | // statistical processing of the remaining values: |
104 | for i in vals { |
105 | sum += i |
106 | if i < imin { |
107 | imin = i |
108 | } |
109 | if i > imax { |
110 | imax = i |
111 | } |
112 | } |
113 | res.imin = imin |
114 | res.imax = imax |
115 | if vals.len > 0 { |
116 | res.average = sum / f64(vals.len) |
117 | } |
118 | // |
119 | mut devsum := f64(0.0) |
120 | for i in vals { |
121 | x := f64(i) - res.average |
122 | devsum += (x * x) |
123 | } |
124 | res.stddev = math.sqrt(devsum / f64(vals.len)) |
125 | // eprintln('\novals: $ovals\n vals: $vals\n vals.len: $vals.len | res.imin: $res.imin | res.imax: $res.imax | res.average: $res.average | res.stddev: $res.stddev') |
126 | return res |
127 | } |
128 | |
129 | fn bold(s string) string { |
130 | return term.colorize(term.bold, s) |
131 | } |
132 | |
133 | fn (a Aints) str() string { |
134 | return bold('${a.average:6.2f}') + |
135 | 'ms ± σ: ${a.stddev:4.1f}ms, min: ${a.imin:4}ms, max: ${a.imax:4}ms, runs:${a.values.len:3}, nmins:${a.nmins:2}, nmaxs:${a.nmaxs:2}' |
136 | } |
137 | |
138 | const ( |
139 | max_fail_percent = 100 * 1000 |
140 | max_time = 60 * 1000 // ms |
141 | performance_regression_label = 'Performance regression detected, failing since ' |
142 | ) |
143 | |
144 | fn main() { |
145 | mut context := Context{} |
146 | context.parse_options()! |
147 | context.run() |
148 | context.show_diff_summary() |
149 | } |
150 | |
151 | fn (mut context Context) parse_options() ! { |
152 | mut fp := flag.new_flag_parser(os.args) |
153 | fp.application(os.file_name(os.executable())) |
154 | fp.version('0.0.1') |
155 | fp.description('Repeat command(s) and collect statistics. Note: you have to quote each command, if it contains spaces.') |
156 | fp.arguments_description('CMD1 CMD2 ...') |
157 | fp.skip_executable() |
158 | fp.limit_free_args_to_at_least(1)! |
159 | context.count = fp.int('count', `c`, 10, 'Repetition count.') |
160 | context.series = fp.int('series', `s`, 2, 'Series count. `-s 2 -c 4 a b` => aaaabbbbaaaabbbb, while `-s 3 -c 2 a b` => aabbaabbaabb.') |
161 | context.warmup = fp.int('warmup', `w`, 2, 'Warmup runs. These are done *only at the start*, and are ignored.') |
162 | context.show_help = fp.bool('help', `h`, false, 'Show this help screen.') |
163 | context.use_newline = fp.bool('newline', `n`, false, 'Use \\n, do not overwrite the last line. Produces more output, but easier to diagnose.') |
164 | context.show_output = fp.bool('output', `O`, false, 'Show command stdout/stderr in the progress indicator for each command. Note: slower, for verbose commands.') |
165 | context.verbose = fp.bool('verbose', `v`, false, 'Be more verbose.') |
166 | context.fail_on_maxtime = fp.int('max_time', `m`, max_time, 'Fail with exit code 2, when first cmd takes above M milliseconds (regression).') |
167 | context.fail_on_regress_percent = fp.int('fail_percent', `f`, max_fail_percent, 'Fail with exit code 3, when first cmd is X% slower than the rest (regression).') |
168 | context.cmd_template = fp.string('template', `t`, '{T}', 'Command template. {T} will be substituted with the current command.') |
169 | cmd_params := fp.string_multi('parameter', `p`, 'A parameter substitution list. `{p}=val1,val2,val2` means that {p} in the template, will be substituted with each of val1, val2, val3.') |
170 | context.nmins = fp.int('nmins', `i`, 0, 'Ignore the BOTTOM X results (minimum execution time). Makes the results more robust to performance flukes.') |
171 | context.nmaxs = fp.int('nmaxs', `a`, 1, 'Ignore the TOP X results (maximum execution time). Makes the results more robust to performance flukes.') |
172 | for p in cmd_params { |
173 | parts := p.split(':') |
174 | if parts.len > 1 { |
175 | context.cmd_params[parts[0]] = parts[1].split(',') |
176 | } |
177 | } |
178 | if context.show_help { |
179 | println(fp.usage()) |
180 | exit(0) |
181 | } |
182 | if context.verbose { |
183 | scripting.set_verbose(true) |
184 | } |
185 | commands := fp.finalize() or { |
186 | eprintln('Error: ${err}') |
187 | exit(1) |
188 | } |
189 | context.commands = context.expand_all_commands(commands) |
190 | context.results = []CmdResult{len: context.commands.len, cap: 20, init: CmdResult{ |
191 | outputs: []string{cap: 500} |
192 | timings: []int{cap: 500} |
193 | }} |
194 | if context.use_newline { |
195 | context.cline = '\n' |
196 | context.cgoback = '\n' |
197 | } else { |
198 | context.cline = '\r' + term.h_divider('') |
199 | context.cgoback = '\r' |
200 | } |
201 | } |
202 | |
203 | fn flushed_print(s string) { |
204 | print(s) |
205 | flush_stdout() |
206 | } |
207 | |
208 | fn (mut context Context) clear_line() { |
209 | flushed_print(context.cline) |
210 | } |
211 | |
212 | fn (mut context Context) expand_all_commands(commands []string) []string { |
213 | mut all_commands := []string{} |
214 | for cmd in commands { |
215 | maincmd := context.cmd_template.replace('{T}', cmd) |
216 | mut substituted_commands := []string{} |
217 | substituted_commands << maincmd |
218 | for paramk, paramlist in context.cmd_params { |
219 | for paramv in paramlist { |
220 | mut new_substituted_commands := []string{} |
221 | for cscmd in substituted_commands { |
222 | scmd := cscmd.replace(paramk, paramv) |
223 | new_substituted_commands << scmd |
224 | } |
225 | for sc in new_substituted_commands { |
226 | substituted_commands << sc |
227 | } |
228 | } |
229 | } |
230 | for sc in substituted_commands { |
231 | all_commands << sc |
232 | } |
233 | } |
234 | mut unique := map[string]int{} |
235 | for x in all_commands { |
236 | if x.contains('{') && x.contains('}') { |
237 | continue |
238 | } |
239 | unique[x] = 1 |
240 | } |
241 | return unique.keys() |
242 | } |
243 | |
244 | fn (mut context Context) run() { |
245 | mut run_warmups := 0 |
246 | for si in 1 .. context.series + 1 { |
247 | for icmd, cmd in context.commands { |
248 | mut runs := 0 |
249 | mut duration := 0 |
250 | mut sum := 0 |
251 | mut oldres := '' |
252 | println('Series: ${si:4}/${context.series:-4}, command: ${cmd}') |
253 | if context.warmup > 0 && run_warmups < context.commands.len { |
254 | for i in 1 .. context.warmup + 1 { |
255 | flushed_print('${context.cgoback}warming up run: ${i:4}/${context.warmup:-4} for ${cmd:-50s} took ${duration:6} ms ...') |
256 | mut sw := time.new_stopwatch() |
257 | res := os.execute(cmd) |
258 | if res.exit_code != 0 { |
259 | continue |
260 | } |
261 | duration = int(sw.elapsed().milliseconds()) |
262 | } |
263 | run_warmups++ |
264 | } |
265 | context.clear_line() |
266 | for i in 1 .. (context.count + 1) { |
267 | avg := f64(sum) / f64(i) |
268 | flushed_print('${context.cgoback}Average: ${avg:9.3f}ms | run: ${i:4}/${context.count:-4} | took ${duration:6} ms') |
269 | if context.show_output { |
270 | flushed_print(' | result: ${oldres:s}') |
271 | } |
272 | mut sw := time.new_stopwatch() |
273 | res := scripting.exec(cmd) or { continue } |
274 | duration = int(sw.elapsed().milliseconds()) |
275 | if res.exit_code != 0 { |
276 | eprintln('${i:10} non 0 exit code for cmd: ${cmd}') |
277 | continue |
278 | } |
279 | trimed_output := res.output.trim_right('\r\n') |
280 | trimed_normalized := trimed_output.replace('\r\n', '\n') |
281 | lines := trimed_normalized.split('\n') |
282 | for line in lines { |
283 | context.results[icmd].outputs << line |
284 | } |
285 | context.results[icmd].timings << duration |
286 | sum += duration |
287 | runs++ |
288 | oldres = res.output.replace('\n', ' ') |
289 | } |
290 | context.results[icmd].cmd = cmd |
291 | context.results[icmd].icmd = icmd |
292 | context.results[icmd].runs += runs |
293 | context.results[icmd].atiming = new_aints(context.results[icmd].timings, context.nmins, |
294 | context.nmaxs) |
295 | context.clear_line() |
296 | flushed_print(context.cgoback) |
297 | mut m := map[string][]int{} |
298 | ioutputs := context.results[icmd].outputs |
299 | for o in ioutputs { |
300 | x := o.split(':') |
301 | if x.len > 1 { |
302 | k := x[0] |
303 | v := x[1].trim_left(' ').int() |
304 | m[k] << v |
305 | } |
306 | } |
307 | mut summary := map[string]Aints{} |
308 | for k, v in m { |
309 | // show a temporary summary for the current series/cmd cycle |
310 | s := new_aints(v, context.nmins, context.nmaxs) |
311 | println(' ${k}: ${s}') |
312 | summary[k] = s |
313 | } |
314 | // merge current raw results to the previous ones |
315 | old_oms := context.results[icmd].oms.move() |
316 | mut new_oms := map[string][]int{} |
317 | for k, v in m { |
318 | if old_oms[k].len == 0 { |
319 | new_oms[k] = v |
320 | } else { |
321 | new_oms[k] << old_oms[k] |
322 | new_oms[k] << v |
323 | } |
324 | } |
325 | context.results[icmd].oms = new_oms.move() |
326 | // println('') |
327 | } |
328 | } |
329 | // create full summaries, taking account of all runs |
330 | for icmd in 0 .. context.results.len { |
331 | mut new_full_summary := map[string]Aints{} |
332 | for k, v in context.results[icmd].oms { |
333 | new_full_summary[k] = new_aints(v, context.nmins, context.nmaxs) |
334 | } |
335 | context.results[icmd].summary = new_full_summary.move() |
336 | } |
337 | } |
338 | |
339 | fn (mut context Context) show_diff_summary() { |
340 | context.results.sort_with_compare(fn (a &CmdResult, b &CmdResult) int { |
341 | if a.atiming.average < b.atiming.average { |
342 | return -1 |
343 | } |
344 | if a.atiming.average > b.atiming.average { |
345 | return 1 |
346 | } |
347 | return 0 |
348 | }) |
349 | println('Summary (commands are ordered by ascending mean time), after ${context.series} series of ${context.count} repetitions:') |
350 | base := context.results[0].atiming.average |
351 | mut first_cmd_percentage := f64(100.0) |
352 | mut first_marker := '' |
353 | for i, r in context.results { |
354 | first_marker = ' ' |
355 | cpercent := (r.atiming.average / base) * 100 - 100 |
356 | if r.icmd == 0 { |
357 | first_marker = bold('>') |
358 | first_cmd_percentage = cpercent |
359 | } |
360 | println(' ${first_marker}${(i + 1):3} | ${cpercent:5.1f}% slower | ${r.cmd:-57s} | ${r.atiming}') |
361 | } |
362 | $if debugcontext ? { |
363 | println('context: ${context}') |
364 | } |
365 | if int(base) > context.fail_on_maxtime { |
366 | flushed_print(performance_regression_label) |
367 | println('average time: ${base:6.1f} ms > ${context.fail_on_maxtime} ms threshold.') |
368 | exit(2) |
369 | } |
370 | if context.fail_on_regress_percent == max_fail_percent || context.results.len < 2 { |
371 | return |
372 | } |
373 | fail_threshold_max := f64(context.fail_on_regress_percent) |
374 | if first_cmd_percentage > fail_threshold_max { |
375 | flushed_print(performance_regression_label) |
376 | println('${first_cmd_percentage:5.1f}% > ${fail_threshold_max:5.1f}% threshold.') |
377 | exit(3) |
378 | } |
379 | } |