Benchmarks and hermit-bench interface

Cargo.toml

@@ -4,6 +4,9 @@ members = [
     "benches/alloc",
     "benches/micro",
     "benches/netbench",
+    "benches/mutex",
+    "benches/startup", 
+    "benches/multithreaded",
     "examples/axum",
     "examples/demo",
     "examples/fuse_test",
@@ -20,7 +23,6 @@ members = [
     "examples/tokio",
     "examples/webserver",
     "examples/dns",
-    "examples/mutex",
     "examples/wasm-test",
     "examples/hermit-wasm",
     "examples/vsock",

benches/alloc/Cargo.toml

@@ -5,6 +5,7 @@ edition = "2021"
 
 [dependencies]
 fastrand = "2.0.0"
+hermit_bench_output = "0.1.0"
 
 [target.'cfg(target_os = "hermit")'.dependencies]
 hermit = { path = "../../hermit", default-features = false }

benches/alloc/src/main.rs

@@ -36,12 +36,13 @@ use std::time::Instant;
 
 #[cfg(target_os = "hermit")]
 use hermit as _;
+use hermit_bench_output::log_benchmark_data;
 
 const BENCH_DURATION: f64 = 3.0;
 
 fn main() {
 	let bench_alloc = benchmark_allocator();
-	print_bench_results("Default allocator", &bench_alloc);
+	print_bench_results(&bench_alloc);
 }
 
 /// Result of a bench run.
@@ -152,38 +153,31 @@ fn benchmark_allocator() -> BenchRunResults {
 	}
 }
 
-fn print_bench_results(bench_name: &str, res: &BenchRunResults) {
-	println!("RESULTS OF BENCHMARK: {bench_name}");
-	println!(
-        " {:7} allocation attempts, {:7} successful allocations, {:7} pre-fail allocations, {:7} deallocations",
-        res.allocation_attempts,
-        res.successful_allocations,
-        res.pre_fail_allocations,
-        res.deallocations
-    );
-
-	println!(
-        "            CATEGORY | OCTILE 0       1       2       3       4       5       6       7       8 | AVERAGE"
-    );
-	println!(
-        "---------------------|--------------------------------------------------------------------------|---------"
-    );
-	print_measurement_set(&res.all_alloc_measurements, "All Allocations");
-	print_measurement_set(&res.nofail_alloc_measurements, "Pre-Fail Allocations");
-	print_measurement_set(&res.dealloc_measurements, "Deallocations");
-}
+fn print_bench_results(res: &BenchRunResults) {
+	let allocation_success =
+		(res.successful_allocations as f64 / res.allocation_attempts as f64) * 100.0;
+	log_benchmark_data("Allocation success", "%", allocation_success);
 
-fn print_measurement_set(measurements: &[u64], set_name: &str) {
-	print!("{set_name:>20} | ");
-	for i in 0..=8 {
-		print!(
-			"{:>8}",
-			measurements[(measurements.len() / 8 * i).min(measurements.len() - 1)]
-		);
-	}
+	let deallocation_success =
+		(res.deallocations as f64 / res.successful_allocations as f64) * 100.0;
+	log_benchmark_data("Deallocation success", "%", deallocation_success);
 
-	println!(
-		" | {:>7}   ticks",
-		measurements.iter().sum::<u64>() / measurements.len() as u64
+	let pre_fail_alloc = (res.pre_fail_allocations as f64 / res.allocation_attempts as f64) * 100.0;
+	log_benchmark_data("Pre-fail Allocations", "%", pre_fail_alloc);
+
+	let avg_all_alloc = res.all_alloc_measurements.iter().sum::<u64>() as f64
+		/ res.all_alloc_measurements.len() as f64;
+	log_benchmark_data("Average Allocation time", "Ticks", avg_all_alloc);
+
+	let avg_nofail_alloc = res.nofail_alloc_measurements.iter().sum::<u64>() as f64
+		/ res.nofail_alloc_measurements.len() as f64;
+	log_benchmark_data(
+		"Average Allocation time (no fail)",
+		"Ticks",
+		avg_nofail_alloc,
 	);
+
+	let avg_dealloc =
+		res.dealloc_measurements.iter().sum::<u64>() as f64 / res.dealloc_measurements.len() as f64;
+	log_benchmark_data("Average Deallocation time", "Ticks", avg_dealloc);
 }

benches/micro/Cargo.toml

@@ -5,6 +5,7 @@ edition = "2021"
 
 [dependencies]
 rayon = "1.5"
+hermit_bench_output = "0.1.1"
 
 [target.'cfg(target_os = "hermit")'.dependencies]
 hermit = { path = "../../hermit", default-features = false }

benches/micro/src/benches/mod.rs

@@ -7,6 +7,8 @@ use std::net::{TcpListener, TcpStream};
 use std::time::Instant;
 use std::{env, str, thread, vec};
 
+use hermit_bench_output::{log_benchmark_data, log_benchmark_data_with_group};
+
 extern "C" {
 	pub fn memcpy(dest: *mut c_void, src: *const c_void, n: usize) -> *mut c_void;
 	pub fn memset(dest: *mut c_void, c: u8, n: usize) -> *mut c_void;
@@ -47,25 +49,29 @@ extern "C" {
 pub fn bench_syscall() -> Result<(), ()> {
 	let n = 1000000;
 
-	let ticks = unsafe {
+	let ticks = {
 		// cache warmup
 		#[cfg(target_os = "hermit")]
-		let _ = sys_getpid();
+		let _ = unsafe { sys_getpid() };
 		#[cfg(target_os = "linux")]
-		let _ = syscalls::syscall!(syscalls::Sysno::getpid);
+		let _ = unsafe { syscalls::syscall!(syscalls::Sysno::getpid) };
 		let _ = get_timestamp();
 
 		let start = get_timestamp();
 		for _ in 0..n {
 			#[cfg(target_os = "hermit")]
-			let _ = sys_getpid();
+			let _ = unsafe { sys_getpid() };
 			#[cfg(target_os = "linux")]
-			let _ = syscalls::syscall!(syscalls::Sysno::getpid);
+			let _ = unsafe { syscalls::syscall!(syscalls::Sysno::getpid) };
 		}
 		get_timestamp() - start
 	};
 
-	println!("Time {} for a system call (in ticks)", ticks / n);
+	hermit_bench_output::log_benchmark_data(
+		"Time for syscall (getpid)",
+		"ticks",
+		ticks as f64 / n as f64,
+	);
 
 	Ok(())
 }
@@ -84,7 +90,12 @@ pub fn bench_sched_one_thread() -> Result<(), ()> {
 	}
 	let ticks = get_timestamp() - start;
 
-	println!("Scheduling time {} ticks (1 thread)", ticks / n);
+	hermit_bench_output::log_benchmark_data_with_group(
+		"1 thread",
+		"ticks",
+		ticks as f64 / n as f64,
+		"Scheduling time",
+	);
 
 	Ok(())
 }
@@ -119,9 +130,11 @@ pub fn bench_sched_two_threads() -> Result<(), ()> {
 		t.join().unwrap();
 	}
 
-	println!(
-		"Scheduling time {} ticks (2 threads)",
-		ticks / (nthreads * n)
+	hermit_bench_output::log_benchmark_data_with_group(
+		"2 threads",
+		"ticks",
+		ticks as f64 / (nthreads * n) as f64,
+		"Scheduling time",
 	);
 
 	Ok(())
@@ -140,10 +153,11 @@ fn memcpy_builtin(n: usize) {
 		dst.copy_from_slice(src);
 	}
 
-	println!(
-		"memcpy_builtin:  {} block size, {} MByte/s",
-		n,
-		(NR_RUNS * n) as f64 / (1024.0 * 1024.0 * now.elapsed().as_secs_f64())
+	hermit_bench_output::log_benchmark_data_with_group(
+		&format!("(built_in) block size {n}"),
+		"MByte/s",
+		(NR_RUNS * n) as f64 / (1024.0 * 1024.0 * now.elapsed().as_secs_f64()),
+		"Memcpy speed",
 	);
 }
 
@@ -160,10 +174,11 @@ fn memset_builtin(n: usize) {
 		}
 	}
 
-	println!(
-		"memset_builtin:  {} block, {} MByte/s",
-		n,
-		((NR_RUNS * n) >> 20) as f64 / now.elapsed().as_secs_f64()
+	hermit_bench_output::log_benchmark_data_with_group(
+		&format!("(built_in) block size {n}"),
+		"MByte/s",
+		((NR_RUNS * n) >> 20) as f64 / now.elapsed().as_secs_f64(),
+		"Memset speed",
 	);
 }
 
@@ -185,10 +200,11 @@ fn memcpy_rust(n: usize) {
 		}
 	}
 
-	println!(
-		"memcpy_rust:  {} block, {} MByte/s",
-		n,
-		((NR_RUNS * n) >> 20) as f64 / now.elapsed().as_secs_f64()
+	hermit_bench_output::log_benchmark_data_with_group(
+		&format!("(rust) block size {n}"),
+		"MByte/s",
+		((NR_RUNS * n) >> 20) as f64 / now.elapsed().as_secs_f64(),
+		"Memcpy speed",
 	);
 }
 
@@ -205,26 +221,27 @@ fn memset_rust(n: usize) {
 		}
 	}
 
-	println!(
-		"memset_rust:  {} block, {} MByte/s",
-		n,
-		((NR_RUNS * n) >> 20) as f64 / now.elapsed().as_secs_f64()
+	hermit_bench_output::log_benchmark_data_with_group(
+		&format!("(rust) block size {n}"),
+		"MByte/s",
+		((NR_RUNS * n) >> 20) as f64 / now.elapsed().as_secs_f64(),
+		"Memset speed",
 	);
 }
 
 pub fn bench_mem() -> Result<(), ()> {
-	memcpy_builtin(4096);
-	memcpy_builtin(1048576);
-	memcpy_builtin(16 * 1048576);
-	memset_builtin(4096);
-	memset_builtin(1048576);
-	memset_builtin(16 * 1048576);
-	memcpy_rust(4096);
-	memcpy_rust(1048576);
-	memcpy_rust(16 * 1048576);
-	memset_rust(4096);
-	memset_rust(1048576);
-	memset_rust(16 * 1048576);
+	memcpy_builtin(black_box(4096));
+	memcpy_builtin(black_box(1048576));
+	memcpy_builtin(black_box(16 * 1048576));
+	memset_builtin(black_box(4096));
+	memset_builtin(black_box(1048576));
+	memset_builtin(black_box(16 * 1048576));
+	memcpy_rust(black_box(4096));
+	memcpy_rust(black_box(1048576));
+	memcpy_rust(black_box(16 * 1048576));
+	memset_rust(black_box(4096));
+	memset_rust(black_box(1048576));
+	memset_rust(black_box(16 * 1048576));
 
 	Ok(())
 }

benches/multithreaded/Cargo.toml

@@ -0,0 +1,12 @@
+[package]
+name = "multithreaded_benchmark"
+authors = ["Carl Wachter"]
+edition = "2021"
+
+[dependencies]
+hermit_bench_output = "0.1.0"
+
+[target.'cfg(target_os = "hermit")'.dependencies]
+hermit = { path = "../../hermit", default-features = false }
+
+[features]