The idea is to add dummy IO port writes in the firmware, kernel and guest OS that will trigger VM exits. One can then ftrace those from the host and get kernel timestamp for each and every one of them.
This is very limited and only provides boot time stamps but allows to measure both the guest kernel and firmware boot times.
In this example we're using 0xf4
as the dummy port, and I patched the guest OVMF and kernel.
We're adding a trace as early as possible in the OVMF code path:
diff --git a/OvmfPkg/Sec/X64/SecEntry.nasm b/OvmfPkg/Sec/X64/SecEntry.nasm
index d76adcffd8..c5459ba970 100644
--- a/OvmfPkg/Sec/X64/SecEntry.nasm
+++ b/OvmfPkg/Sec/X64/SecEntry.nasm
@@ -40,6 +40,9 @@ extern ASM_PFX(SecCoreStartupWithStack)
;
global ASM_PFX(_ModuleEntryPoint)
ASM_PFX(_ModuleEntryPoint):
+ mov dx, 0xf4
+ add ax, 80
+ out dx, ax
;
; Fill the temporary RAM with the initial stack value.
We're trying to trace when userspace starts:
diff --git a/init/main.c b/init/main.c
index 5e13c544bbf4..9853f1bcd2d3 100644
--- a/init/main.c
+++ b/init/main.c
@@ -533,6 +533,8 @@ asmlinkage __visible void __init start_kernel(void)
char *command_line;
char *after_dashes;
+ outb(81, 0xf4);
+
set_task_stack_end_magic(&init_task);
smp_setup_processor_id();
debug_objects_early_init();
@@ -1070,6 +1072,8 @@ static int __ref kernel_init(void *unused)
rcu_end_inkernel_boot();
+ outb(82, 0xf4);
+
if (ramdisk_execute_command) {
ret = run_init_process(ramdisk_execute_command);
if (!ret)
We're going to use the host kernel tracing framework to filter KVM PIO VM exits events:
cd /sys/kernel/debug/tracing
# Disable KVM traces
echo 0 > events/kvm/enable
# Filter all non 0xf4 PIO events out
echo "port == 0xf4" > events/kvm/kvm_pio/filter
# Enable KVM traces back
echo 1 > events/kvm/enable
# Dump traces
cat trace_pipe
https://github.com/libguestfs/libguestfs/tree/master/utils/boot-benchmark https://github.com/libguestfs/libguestfs/tree/master/utils/boot-analysis