tools: make fast.v results more robust to AWS spikes (increase samples, discard the top few)

cmd/tools/fast/fast.v

@@ -3,91 +3,115 @@
 // that can be found in the LICENSE file.
 import os
 import time
+import arrays
+
+const warmup_samples = 2
+
+const max_samples = 10
+
+const discard_highest_samples = 6
 
 const voptions = ' -skip-unused -show-timings -stats '
 
-const exe = os.executable()
+const fast_dir = os.dir(@FILE)
 
-const fast_dir = os.dir(exe)
+const vdir = os.dir(os.dir(os.dir(fast_dir)))
 
-const vdir = @VEXEROOT
+fn elog(msg string) {
+	eprintln('$time.now().format_ss_micro() $msg')
+}
 
 fn main() {
-	dump(fast_dir)
+	total_sw := time.new_stopwatch()
-	dump(vdir)
+	elog('fast.html generator start')
+	defer {
+		elog('fast.html generator end, total: ${total_sw.elapsed().milliseconds():6} ms')
+	}
+	//
+	mut ccompiler_path := 'tcc'
+	if vdir.contains('/tmp/cirrus-ci-build') {
+		ccompiler_path = 'clang'
+	}
+	if os.args.contains('-clang') {
+		ccompiler_path = 'clang'
+	}
+	elog('fast_dir: $fast_dir | vdir: $vdir | compiler: $ccompiler_path')
+
 	os.chdir(fast_dir)!
 	if !os.exists('$vdir/v') && !os.is_dir('$vdir/vlib') {
-		println('fast.html generator needs to be located in `v/cmd/tools/fast`')
+		elog('fast.html generator needs to be located in `v/cmd/tools/fast`')
+		exit(1)
 	}
-	println('fast.html generator\n')
+	if !os.exists('table.html') {
+		os.create('table.html')!
+	}
+
 	if !os.args.contains('-noupdate') {
-		println('Fetching updates...')
+		elog('Fetching updates...')
 		ret := os.system('$vdir/v up')
 		if ret != 0 {
-			println('failed to update V')
+			elog('failed to update V, exit_code: $ret')
 			return
 		}
 	}
 
 	// fetch the last commit's hash
 	commit := exec('git rev-parse HEAD')[..8]
-	if !os.exists('table.html') {
-		os.create('table.html')!
-	}
-	mut table := os.read_file('table.html')!
 	if os.exists('website/index.html') {
 		uploaded_index := os.read_file('website/index.html')!
 		if uploaded_index.contains('>$commit<') {
-			println('nothing to benchmark')
+			elog('NOTE: commit $commit had been benchmarked already.')
-			exit(1)
+			if !os.args.contains('-force') {
+				elog('nothing more to do')
 				return
 			}
 		}
+	}
+
+	os.chdir(vdir)!
 	message := exec('git log --pretty=format:"%s" -n1 $commit')
-	println('\nBenchmarking commit $commit "$message"')
+	commit_date := exec('git log -n1 --pretty="format:%at" $commit')
+	date := time.unix(commit_date.i64())
+
+	elog('Benchmarking commit $commit , with commit message: "$message", commit_date: $commit_date, date: $date')
 
 	// build an optimized V
-	println('  Building vprod...')
+	if os.args.contains('-do-not-rebuild-vprod') {
-	os.chdir(vdir)!
+		if !os.exists('vprod') {
+			elog('Exiting, since if you use `-do-not-rebuild-vprod`, you should already have a `$vdir/vprod` executable, but it is missing!')
+			return
+		}
+	} else {
+		elog('  Building vprod...')
 		if os.args.contains('-noprod') {
 			exec('./v -o vprod cmd/v') // for faster debugging
 		} else {
 			exec('./v -o vprod -prod -prealloc cmd/v')
 		}
+	}
 
+	if !os.args.contains('-do-not-rebuild-caches') {
+		elog('clearing caches...')
 		// cache vlib modules
 		exec('$vdir/v wipe-cache')
-	exec('$vdir/v -o v2 -prod cmd/v')
+		exec('$vdir/v -o vwarm_caches -cc $ccompiler_path cmd/v')
+	}
 
 	// measure
 	diff1 := measure('$vdir/vprod $voptions -o v.c cmd/v', 'v.c')
-	mut tcc_path := 'tcc'
+	diff2 := measure('$vdir/vprod $voptions -cc $ccompiler_path -o v2 cmd/v', 'v2')
-	$if freebsd {
-		tcc_path = '/usr/local/bin/tcc'
-		if vdir.contains('/tmp/cirrus-ci-build') {
-			tcc_path = 'clang'
-		}
-	}
-	if os.args.contains('-clang') {
-		tcc_path = 'clang'
-	}
-
-	diff2 := measure('$vdir/vprod $voptions -cc $tcc_path -o v2 cmd/v', 'v2')
 	diff3 := 0 // measure('$vdir/vprod -native $vdir/cmd/tools/1mil.v', 'native 1mil')
-	diff4 := measure('$vdir/vprod -usecache $voptions -cc clang examples/hello_world.v',
+	diff4 := measure('$vdir/vprod $voptions -cc $ccompiler_path -usecache examples/hello_world.v',
 		'hello.v')
 	vc_size := os.file_size('v.c') / 1000
-	scan, parse, check, cgen, vlines := measure_steps(vdir)
+	scan, parse, check, cgen, vlines := measure_steps_minimal(vdir)!
 
-	commit_date := exec('git log -n1 --pretty="format:%at" $commit')
+	html_message := message.replace_each(['<', '&lt;', '>', '&gt;'])
-	date := time.unix(commit_date.int())
 
 	os.chdir(fast_dir)!
-	mut out := os.create('table.html')!
-
 	// place the new row on top
-	html_message := message.replace_each(['<', '&lt;', '>', '&gt;'])
+	table := os.read_file('table.html')!
-	table =
+	new_table :=
 		'	<tr>
 		<td>$date.format()</td>
 		<td><a target=_blank href="https://github.com/vlang/v/commit/$commit">$commit</a></td>
@@ -104,28 +128,27 @@ fn main() {
 		<td>$vlines</td>
 		<td>${int(f64(vlines) / f64(diff1) * 1000.0)}</td>
 	</tr>\n' +
-		table.trim_space()
+		table.trim_space() + '\n'
-	out.writeln(table)!
+	os.write_file('table.html', new_table)!
-	out.close()
 
 	// regenerate index.html
 	header := os.read_file('header.html')!
 	footer := os.read_file('footer.html')!
 	mut res := os.create('index.html')!
 	res.writeln(header)!
-	res.writeln(table)!
+	res.writeln(new_table)!
 	res.writeln(footer)!
 	res.close()
 
 	// upload the result to github pages
 	if os.args.contains('-upload') {
-		println('uploading...')
+		elog('uploading...')
 		os.chdir('website')!
 		os.execute_or_exit('git checkout gh-pages')
-		os.cp('../index.html', 'index.html')!
+		os.mv('../index.html', 'index.html')!
-		os.rm('../index.html')!
 		os.system('git commit -am "update benchmark"')
 		os.system('git push origin gh-pages')
+		elog('uploading done')
 	}
 }
 
@@ -136,31 +159,50 @@ fn exec(s string) string {
 
 // measure returns milliseconds
 fn measure(cmd string, description string) int {
-	println('  Measuring $description')
+	elog('  Measuring $description, warmups: $warmup_samples, samples: $max_samples, discard: $discard_highest_samples, with cmd: `$cmd`')
-	println('  Warming up...')
+	for _ in 0 .. warmup_samples {
-	println(cmd)
-	for _ in 0 .. 3 {
 		exec(cmd)
 	}
-	println('  Building...')
 	mut runs := []int{}
-	for r in 0 .. 5 {
+	for r in 0 .. max_samples {
-		println('  Sample ${r + 1}/5')
+		print('  Sample ${r + 1:2}/${max_samples:2} ... ')
 		sw := time.new_stopwatch()
 		exec(cmd)
-		runs << int(sw.elapsed().milliseconds())
+		sample := int(sw.elapsed().milliseconds())
+		runs << sample
+		println('$sample ms')
+		flush_stdout()
 	}
-	// discard lowest and highest time
 	runs.sort()
-	runs = runs[1..4]
+	elog('   runs before discarding: $runs, avg: ${f64(arrays.sum(runs) or { 0 }) / runs.len:5.2f}')
-	mut sum := 0
+	// Discard the highest times, since on AWS, they are caused by random load spikes,
-	for run in runs {
+	// that are unpredictable, add noise and skew the statistics, without adding useful
-		sum += run
+	// insights:
+	for _ in 0 .. discard_highest_samples {
+		runs.pop()
 	}
-	return int(sum / 3)
+	elog('   runs  after discarding: $runs, avg: ${f64(arrays.sum(runs) or { 0 }) / runs.len:5.2f}')
+	return int(f64(arrays.sum(runs) or { 0 }) / runs.len)
 }
 
-fn measure_steps(vdir string) (int, int, int, int, int) {
+fn measure_steps_minimal(vdir string) !(int, int, int, int, int) {
+	elog('measure_steps_minimal $vdir, samples: $max_samples')
+	mut scans, mut parses, mut checks, mut cgens, mut vliness := []int{}, []int{}, []int{}, []int{}, []int{}
+	for i in 0 .. max_samples {
+		scan, parse, check, cgen, vlines := measure_steps_one_sample(vdir)
+		scans << scan
+		parses << parse
+		checks << check
+		cgens << cgen
+		vliness << vlines
+		elog('    [${i:2}/${max_samples:2}] scan: $scan ms, min parse: $parse ms, min check: $check ms, min cgen: $cgen ms, min vlines: $vlines ms')
+	}
+	scan, parse, check, cgen, vlines := arrays.min(scans)!, arrays.min(parses)!, arrays.min(checks)!, arrays.min(cgens)!, arrays.min(vliness)!
+	elog('measure_steps_minimal => min scan: $scan ms, min parse: $parse ms, min check: $check ms, min cgen: $cgen ms, min vlines: $vlines ms')
+	return scan, parse, check, cgen, vlines
+}
+
+fn measure_steps_one_sample(vdir string) (int, int, int, int, int) {
 	resp := os.execute_or_exit('$vdir/vprod $voptions -o v.c cmd/v')
 
 	mut scan, mut parse, mut check, mut cgen, mut vlines := 0, 0, 0, 0, 0

cmd/tools/fast/fast_job.v

@@ -41,7 +41,7 @@ fn main() {
 			continue
 		}
 		if res_pull.output.contains('Already up to date.') {
-			if os.args[1] or { '' } == '-force-update' {
+			if os.args.contains('-force-update') {
 				elog('The repository was already updated, but -force-update was passed too.')
 			} else {
 				delay()