hello_world performance regression

[jbreitbart]

The execution time of hello_world degraded by about 13% over the last several month.

Version checked in the uhyve repo:

time:   [224.29 ms 225.64 ms 226.60 ms]

Current master version with all features enabled, i.e. fsgsbase, pci, acpi:

time:   [253.29 ms 255.99 ms 258.55 ms]

Current master version with pci and acpi enabled:

time:   [250.02 ms 252.49 ms 254.95 ms]

Current master version with pci enabled:

time:   [250.88 ms 254.38 ms 257.67 ms]

Current master version with acpi enabled:

time:   [252.18 ms 254.48 ms 256.79 ms]

It seems to be that regardless of which feature is enabled, execution time is slower than it used to be and I am not sure why it is. The version checked in the uhyve repo seems to have at least pci enabled:

 ᨂ target/release/uhyve -v benches_data/hello_world_old
[0][INFO] Welcome to HermitCore-rs 0.3.37
[0][INFO] Kernel starts at 0x400000
[0][INFO] BSS starts at 0x5ca000
[0][INFO] TLS starts at 0x553dd0 (size 184 Bytes)
[0][INFO] Total memory size: 64 MB
[0][INFO] Kernel region: [0x400000 - 0x600000]
[0][INFO] A pure Rust application is running on top of HermitCore!
[0][INFO] Heap: size 50 MB, start address 0x600000
[0][INFO] Heap is located at 0x600000 -- 0x3800000 (0 Bytes unmapped)
[0][INFO]
[0][INFO] ===================== PHYSICAL MEMORY FREE LIST ======================
[0][INFO] 0x00000003800000 - 0x00000004000000
[0][INFO] ======================================================================
[0][INFO]
[0][INFO]
[0][INFO] ================== KERNEL VIRTUAL MEMORY FREE LIST ===================
[0][INFO] 0x00000003800000 - 0x00800000000000
[0][INFO] ======================================================================
[0][INFO]
[0][INFO]
[0][INFO] ========================== CPU INFORMATION ===========================
[0][INFO] Model:                   uhyve - unikernel hypervisor
[0][INFO] Frequency:               3693 MHz (from Hypervisor)
[0][INFO] SpeedStep Technology:    Not Available
[0][INFO] Features:                MMX SSE SSE2 SSE3 SSSE3 SSE4.1 SSE4.2 AVX AESNI RDRAND FMA MOVBE MCE FXSR XSAVE RDTSCP CLFLUSH TSC-DEADLINE X2APIC HYPERVISOR AVX2 BMI1 BMI2 FSGSBASE
[0][INFO] Physical Address Width:  48 bits
[0][INFO] Linear Address Width:    48 bits
[0][INFO] Supports 1GiB Pages:     Yes
[0][INFO] ======================================================================
[0][INFO]
[0][INFO] HermitCore-rs booted on 2020-12-24 at 11:43:26
[0][INFO]
[0][INFO] ======================== PCI BUS INFORMATION =========================
[0][INFO] 00:00 Ethernet controller [0200]: Red Hat, Inc. Virtio network device [1AF4:1000], MemoryBar: 0xc000 (size 0x10)
[0][INFO] ======================================================================
[0][INFO]
[0][INFO] IOAPIC v0 has 1 entries
[0][INFO] HermitCore is running on uhyve!
[0][INFO] Found virtio device with device id 0x1000
[0][WARN] Legacy Virtio devices are not supported, skipping!
[INFO] Spawn network thread with id 2
[WARN] Ethernet interface not available
Hello World!
[0][INFO] Number of interrupts
[0][INFO] [0][7]: 3

[stlankes]

Hm, difficult to say. I looked in the history and it changed a lot. For instance, I revised the Interface to the PCI drivers and its initialization. We should create a process to monitor the performance changes.

[jbreitbart]

I guess just building old version from git is a reasonable way to identify when it happened. Chances are, that it is just a bug as it seems not to be related to any of the features. Or maybe the features are not yet implemented perfectly.

Anyhow, git bisect[0] should be able to help. even though I am not sure how well it works with submodules.

[0] https://git-scm.com/docs/git-bisect

[jbreitbart]

So, I gave it a try, but I failed to build old versions of this repo. Here is what I did:

1. Get an old commit hash by calling somthing like git rev-list -n 1 --before="2020-08-10 13:37" master
2. Cheking out that commit with git checkout <hash> && git submodule update
3. Setting an old compiler for that directory via rustup override set nightly-2020-07-01
4. Build with cargo clean && cargo build -Z build-std=std,core,alloc,panic_abort --target x86_64-unknown-hermit

Is that fine or am I missing something? When I follow these steps I get signal: 11, SIGSEGV: invalid memory reference from rustc. Here is the complete error message

  error: could not compile `rusty-hermit`

  Caused by:
    process didn't exit successfully: `rustc --crate-name hermit --edition=2018 src/lib.rs --error-format=json --json=diagnostic-rendered-ansi --crate-type staticlib --emit=dep-info,link -C opt-level=1 -C panic=abort -C embed-bitcode=no -C debuginfo=2 -C debug-assertions=on --cfg 'feature="acpi"' --cfg 'feature="default"' --cfg 'feature="pci"' -C metadata=cb82b3bd2931e5a5 -C extra-filename=-cb82b3bd2931e5a5 --out-dir /home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps --target x86_64-unknown-hermit-kernel -C incremental=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/incremental -L dependency=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps -L dependency=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/debug/deps --extern 'noprelude:alloc=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/liballoc-6700b37dcd2cb618.rlib' --extern bitflags=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/libbitflags-8906d5332f6e55fb.rlib --extern 'noprelude:compiler_builtins=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/libcompiler_builtins-8c90b50ae572c4b5.rlib' --extern 'noprelude:core=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/libcore-215ed17ad95cbdff.rlib' --extern log=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/liblog-aac0c3535167ff43.rlib --extern multiboot=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/libmultiboot-874de2c4013bf80d.rlib --extern num=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/libnum-5b5c297c932dd375.rlib --extern num_derive=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/debug/deps/libnum_derive-030eb7efc88f88d8.so --extern num_traits=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/libnum_traits-b65ba7142768480e.rlib --extern x86=/home/jbreitbart/temp/h/rusty-hermit/target/x86_64-unknown-hermit/debug/build/hermit-sys-34dd046e24681a92/out/target/x86_64-unknown-hermit-kernel/debug/deps/libx86-8b2b5c4cc34191e3.rlib -Z unstable-options` (signal: 11, SIGSEGV: invalid memory reference)


  --- stderr
  thread 'main' panicked at 'assertion failed: output.status.success()', hermit-sys/build.rs:51:5
  stack backtrace:
     0: std::panicking::begin_panic
               at /home/jbreitbart/.rustup/toolchains/nightly-2020-09-12-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:505
     1: build_script_build::build_hermit
               at ./build.rs:51
     2: build_script_build::build
               at ./build.rs:97
     3: build_script_build::main
               at ./build.rs:154
     4: core::ops::function::FnOnce::call_once
               at /home/jbreitbart/.rustup/toolchains/nightly-2020-09-12-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ops/function.rs:227
  note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.