Skip to content

Conversation

@mkroening
Copy link
Member

@mkroening mkroening commented Oct 29, 2025

This PR builds on #2021 to make target logging unconditional and removes the corresponding feature.

Before
[            ][0][INFO ] Welcome to Hermit 0.11.0
[            ][0][INFO ] Git version: v0.11.0-762-gb9e34fd (opt-level=0)
[            ][0][INFO ] Enabled features: acpi, pci
[            ][0][INFO ] Built on Wed, 29 Oct 2025 09:03:28 +0000
[            ][0][INFO ] Kernel starts at 0x1600000
[            ][0][INFO ] FDT:
 / {
    compatible = "hermit,multiboot"
    #address-cells = <0x2>
    #size-cells = <0x2>

    memory@0 {
        device_type = "memory"
        reg = <0x0 0x9fc00>
    };

    memory@100000 {
        device_type = "memory"
        reg = <0x100000 0x3fee0000>
    };

    chosen {
        bootargs = [104, 101, 114, 109, 105, 116, 45, 108, 111, 97, 100, 101, 114, 45, 120, 56, 54, 95, 54, 52, 32, 0]
    };
};

[            ][0][INFO ] BSS starts at 0x1839900
[            ][0][INFO ] tls_info = Some(
    TlsInfo {
        start: 0x180fe30,
        filesz: 0x20,
        memsz: 0x70,
        align: 0x8,
    },
)
[            ][0][INFO ] Total memory size: 997 MiB
[            ][0][INFO ] Kernel region: 0x1600000..0x1a00000
[            ][0][INFO ] Minimum memory size: 31 MiB
[            ][0][INFO ] Heap: size 866 MB, start address 0x400000000000
[            ][0][INFO ] Heap is located at 0x400000000000..0x400036200000 (0 Bytes unmapped)
[            ][0][INFO ] FrameAlloc free list:
         0x1c02000..         0x1e00000 (len =           0x1fe000, pages =              510)
        0x37e00000..        0x3ffe0000 (len =          0x81e0000, pages =            33248)
[            ][0][INFO ] PageAlloc free list:
    0x400036200000..    0x800000000000 (len =     0x3fffc9e00000, pages =      17179647488)
[            ][0][INFO ] bootargs = hermit-loader-x86_64 
[    0.340100][0][INFO ] 
[    0.345990][0][INFO ] ========================== CPU INFORMATION ===========================
[    0.350009][0][INFO ] Model:                   Intel Core Processor (Skylake)
[    0.350403][0][INFO ] Frequency:               1004 MHz (from Measurement)
[    0.350896][0][INFO ] SpeedStep Technology:    Not Available
[    0.351311][0][INFO ] Features:                MMX SSE SSE2 SSE3 SSSE3 SSE4.1 SSE4.2 AVX AESNI RDRAND FMA MOVBE MCE FXSR XSAVE RDTSCP CLFLUSH X2APIC HYPERVISOR AVX2 BMI1 BMI2 FSGSBASE RDSEED 
[    0.353128][0][INFO ] Physical Address Width:  40 bits
[    0.353464][0][INFO ] Linear Address Width:    48 bits
[    0.353725][0][INFO ] Supports 1GiB Pages:     No
[    0.353946][0][INFO ] ======================================================================
[    0.354363][0][INFO ] 
[    0.371288][0][INFO ] Hermit booted on 2025-10-29 9:03:34.630983 +00:00:00
[    0.382246][0][INFO ] Found an ACPI revision 0 table at 0xF52E0 with OEM ID "BOCHS "
[    0.400690][0][INFO ] Initialized PCI
[    0.433515][0][INFO ] IOAPIC v32 has 24 entries
[    0.440934][0][INFO ] 
[    0.441222][0][INFO ] ===================== MULTIPROCESSOR INFORMATION =====================
[    0.441567][0][INFO ] APIC in use:             x2APIC
[    0.441806][0][INFO ] Initialized CPUs:        1
[    0.442052][0][INFO ] ======================================================================
[    0.442450][0][INFO ] 
[    0.442630][0][INFO ] Compiled with PCI support
[    0.442897][0][INFO ] Compiled with ACPI support
[    0.443173][0][INFO ] 
[    0.443374][0][INFO ] ======================== PCI BUS INFORMATION =========================
[    0.444278][0][INFO ] 00:00 Unknown Class [0600]: Unknown Vendor Unknown Device [8086:1237]
[    0.445356][0][INFO ] 00:01 Unknown Class [0601]: Unknown Vendor Unknown Device [8086:7000]
[    0.445735][0][INFO ] 00:02 Unknown Class [0300]: Unknown Vendor Unknown Device [1234:1111], BAR0 Memory32 { address: 0xFD000000, size: 0x1000000, prefetchable: true }, BAR2 Memory32 { address: 0xFEBF0000, size: 0x1000, prefetchable: false }
[    0.447154][0][INFO ] 00:03 Unknown Class [0200]: Unknown Vendor Unknown Device [8086:100E], IRQ 11, BAR0 Memory32 { address: 0xFEBC0000, size: 0x20000, prefetchable: false }, BAR1 IO { port: 0xC000 }
[    0.448322][0][INFO ] ======================================================================
[    0.448687][0][INFO ] 
[    0.459678][0][INFO ] Hermit is running on common system!
[    0.502206][0][INFO ] Jumping into application
Hello, world!
Number of interrupts
exit status 0
After
[            ][0][INFO  hermit    ] Welcome to Hermit 0.11.0
[            ][0][INFO  hermit    ] Git version: v0.11.0-763-ga6ee871 (opt-level=0)
[            ][0][INFO  hermit    ] Enabled features: acpi, pci
[            ][0][INFO  hermit    ] Built on Wed, 29 Oct 2025 09:03:59 +0000
[            ][0][INFO  hermit    ] Kernel starts at 0x1600000
[            ][0][INFO  hermit    ] FDT:
 / {
    compatible = "hermit,multiboot"
    #address-cells = <0x2>
    #size-cells = <0x2>

    memory@0 {
        device_type = "memory"
        reg = <0x0 0x9fc00>
    };

    memory@100000 {
        device_type = "memory"
        reg = <0x100000 0x3fee0000>
    };

    chosen {
        bootargs = [104, 101, 114, 109, 105, 116, 45, 108, 111, 97, 100, 101, 114, 45, 120, 56, 54, 95, 54, 52, 32, 0]
    };
};

[            ][0][INFO  hermit    ] BSS starts at 0x1839a00
[            ][0][INFO  hermit    ] tls_info = Some(
    TlsInfo {
        start: 0x180fee0,
        filesz: 0x20,
        memsz: 0x70,
        align: 0x8,
    },
)
[            ][0][INFO  mm        ] Total memory size: 997 MiB
[            ][0][INFO  mm        ] Kernel region: 0x1600000..0x1a00000
[            ][0][INFO  mm        ] Minimum memory size: 31 MiB
[            ][0][INFO  mm        ] Heap: size 866 MB, start address 0x400000000000
[            ][0][INFO  mm        ] Heap is located at 0x400000000000..0x400036200000 (0 Bytes unmapped)
[            ][0][INFO  mm        ] FrameAlloc free list:
         0x1c02000..         0x1e00000 (len =           0x1fe000, pages =              510)
        0x37e00000..        0x3ffe0000 (len =          0x81e0000, pages =            33248)
[            ][0][INFO  mm        ] PageAlloc free list:
    0x400036200000..    0x800000000000 (len =     0x3fffc9e00000, pages =      17179647488)
[            ][0][INFO  env       ] bootargs = hermit-loader-x86_64 
[    0.233697][0][INFO  processor ] 
[    0.239635][0][INFO  processor ] ========================== CPU INFORMATION ===========================
[    0.245024][0][INFO  processor ] Model:                   Intel Core Processor (Skylake)
[    0.247615][0][INFO  processor ] Frequency:               964 MHz (from Measurement)
[    0.248832][0][INFO  processor ] SpeedStep Technology:    Not Available
[    0.249261][0][INFO  processor ] Features:                MMX SSE SSE2 SSE3 SSSE3 SSE4.1 SSE4.2 AVX AESNI RDRAND FMA MOVBE MCE FXSR XSAVE RDTSCP CLFLUSH X2APIC HYPERVISOR AVX2 BMI1 BMI2 FSGSBASE RDSEED 
[    0.252127][0][INFO  processor ] Physical Address Width:  40 bits
[    0.252684][0][INFO  processor ] Linear Address Width:    48 bits
[    0.253211][0][INFO  processor ] Supports 1GiB Pages:     No
[    0.253554][0][INFO  processor ] ======================================================================
[    0.254273][0][INFO  processor ] 
[    0.276679][0][INFO  systemtime] Hermit booted on 2025-10-29 9:04:04.725816 +00:00:00
[    0.290731][0][INFO  acpi      ] Found an ACPI revision 0 table at 0xF52E0 with OEM ID "BOCHS "
[    0.316697][0][INFO  pci       ] Initialized PCI
[    0.426881][0][INFO  apic      ] IOAPIC v32 has 24 entries
[    0.451521][0][INFO  apic      ] 
[    0.454100][0][INFO  apic      ] ===================== MULTIPROCESSOR INFORMATION =====================
[    0.454567][0][INFO  apic      ] APIC in use:             x2APIC
[    0.458581][0][INFO  apic      ] Initialized CPUs:        1
[    0.459022][0][INFO  apic      ] ======================================================================
[    0.459576][0][INFO  apic      ] 
[    0.459829][0][INFO  hermit    ] Compiled with PCI support
[    0.460142][0][INFO  hermit    ] Compiled with ACPI support
[    0.460406][0][INFO  pci       ] 
[    0.460619][0][INFO  pci       ] ======================== PCI BUS INFORMATION =========================
[    0.461551][0][INFO  pci       ] 00:00 Unknown Class [0600]: Unknown Vendor Unknown Device [8086:1237]
[    0.462998][0][INFO  pci       ] 00:01 Unknown Class [0601]: Unknown Vendor Unknown Device [8086:7000]
[    0.463482][0][INFO  pci       ] 00:02 Unknown Class [0300]: Unknown Vendor Unknown Device [1234:1111], BAR0 Memory32 { address: 0xFD000000, size: 0x1000000, prefetchable: true }, BAR2 Memory32 { address: 0xFEBF0000, size: 0x1000, prefetchable: false }
[    0.465064][0][INFO  pci       ] 00:03 Unknown Class [0200]: Unknown Vendor Unknown Device [8086:100E], IRQ 11, BAR0 Memory32 { address: 0xFEBC0000, size: 0x20000, prefetchable: false }, BAR1 IO { port: 0xC000 }
[    0.466006][0][INFO  pci       ] ======================================================================
[    0.466469][0][INFO  pci       ] 
[    0.479977][0][INFO  hermit    ] Hermit is running on common system!
[    0.526124][0][INFO  hermit    ] Jumping into application
Hello, world!
Number of interrupts
exit status 0

@mkroening mkroening self-assigned this Oct 29, 2025
@mkroening mkroening marked this pull request as ready for review October 29, 2025 09:04
Copy link
Member

@jounathaen jounathaen left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it is fine. The double space between INFO and the target bugs me a little, but that's something for another PR 😉

Copy link
Contributor

@sarahspberrypi sarahspberrypi left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure if getting rid of this feature by making it the default is the way to go here. For debugging purposes, I see the appeal but for "normal use", I don't see any benefit of showing these targets.

@mkroening
Copy link
Member Author

mkroening commented Oct 29, 2025

The double space between INFO and the target bugs me a little, but that's something for another PR 😉

I introduced that yesterday in #2021 (0d620cf). The reason for that is to align the different log level names (ERROR, WARN, INFO, DEBUG, and TRACE), compare with env_logger/src/fmt/mod.rs#L478.

Excerpt with `LOG_LEVEL=trace`
[    0.894305][0][INFO  apic      ] 
[    0.894498][0][INFO  apic      ] ===================== MULTIPROCESSOR INFORMATION =====================
[    0.894836][0][INFO  apic      ] APIC in use:             x2APIC
[    0.895090][0][INFO  apic      ] Initialized CPUs:        1
[    0.895310][0][INFO  apic      ] ======================================================================
[    0.895694][0][INFO  apic      ] 
[    0.895863][0][INFO  hermit    ] Compiled with PCI support
[    0.896074][0][INFO  hermit    ] Compiled with ACPI support
[    0.896294][0][INFO  pci       ] 
[    0.896464][0][INFO  pci       ] ======================== PCI BUS INFORMATION =========================
[    0.897248][0][INFO  pci       ] 00:00 Unknown Class [0600]: Unknown Vendor Unknown Device [8086:1237]
[    0.898247][0][INFO  pci       ] 00:01 Unknown Class [0601]: Unknown Vendor Unknown Device [8086:7000]
[    0.898531][0][INFO  pci       ] 00:02 Unknown Class [0300]: Unknown Vendor Unknown Device [1234:1111], BAR0 Memory32 { address: 0xFD000000, size: 0x1000000, prefetchable: true }, BAR2 Memory32 { address: 0xFEBF0000, size: 0x1000, prefetchable: false }
[    0.899580][0][INFO  pci       ] 00:03 Unknown Class [0200]: Unknown Vendor Unknown Device [8086:100E], IRQ 11, BAR0 Memory32 { address: 0xFEBC0000, size: 0x20000, prefetchable: false }, BAR1 IO { port: 0xC000 }
[    0.900420][0][INFO  pci       ] ======================================================================
[    0.900786][0][INFO  pci       ] 
[    0.901613][0][DEBUG scheduler ] Create stacks at 0x400036204000 with a size of 1120 KB
[    0.901903][0][TRACE paging    ] Mapping PageRange { start: Page[4KiB](0x400036205000), end: Page[4KiB](0x40003620d000) } to PhysFrameRange { start: PhysFrame[4KiB](0x1c03000), end: PhysFrame[4KiB](0x1c0b000) } with PageTableFlags(PRESENT | WRITABLE | NO_EXECUTE)
[    0.902541][0][DEBUG paging    ] Had to unmap page Page[4KiB](0x400036205000) before mapping.
[    0.902804][0][DEBUG paging    ] Had to unmap page Page[4KiB](0x400036206000) before mapping.
[    0.903135][0][TRACE paging    ] Mapping PageRange { start: Page[4KiB](0x40003620e000), end: Page[4KiB](0x40003621e000) } to PhysFrameRange { start: PhysFrame[4KiB](0x1c0b000), end: PhysFrame[4KiB](0x1c1b000) } with PageTableFlags(PRESENT | WRITABLE | NO_EXECUTE)
[    0.903954][0][TRACE paging    ] Mapping PageRange { start: Page[4KiB](0x40003621f000), end: Page[4KiB](0x40003631f000) } to PhysFrameRange { start: PhysFrame[4KiB](0x1c1b000), end: PhysFrame[4KiB](0x1d1b000) } with PageTableFlags(PRESENT | WRITABLE | NO_EXECUTE)
[    0.909462][0][DEBUG task      ] Creating new task 1 on core 0
[    0.909744][0][DEBUG processor ] XSAVE area size: 832
[    0.911572][0][DEBUG scheduler ] Creating task 1 with priority 2 on core 0
[    0.912937][0][DEBUG scheduler ] Task is available.
[    0.913308][0][DEBUG scheduler ] Switching task from 0 to 1 (stack 0x0 => 0x40003621df60)
[    0.914974][0][INFO  hermit    ] Hermit is running on common system!
[    0.922136][0][DEBUG interrupts] Register name "COM1" for interrupt 4
[    0.931352][0][DEBUG fs        ] Create directory /tmp
[    0.942020][0][DEBUG fs        ] Create directory /proc
[    0.944640][0][DEBUG fs        ] Open /proc/version, OpenOption(O_RDWR | O_CREAT), AccessPermission(S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP | S_IROTH | S_IWOTH)
[    0.946534][0][DEBUG fs        ] Open file /proc/version with OpenOption(O_RDWR | O_CREAT)
[    0.960043][0][DEBUG interfaces] Setting argv as: []
[    0.960691][0][DEBUG interfaces] Setting envv as: []
[    0.961671][0][INFO  hermit    ] Jumping into application
[    0.978156][0][TRACE syscalls  ] __sys_malloc: allocate memory at 0x40000000fc58 (size 0x400, align 0x1)
Hello, world!
[    0.983916][0][TRACE syscalls  ] sys_free: deallocate memory at 0x40000000fc58 (size 0x400)
[    0.984913][0][DEBUG tasks     ] Exit program with error code 0!
Number of interrupts
exit status 0

Stefan also likes the feature and is okay with always displaying the target (compare with dmesg on Linux).
So if you have nothing else against this, I will merge this later. :)

@sarahspberrypi
Copy link
Contributor

The double space between INFO and the target bugs me a little, but that's something for another PR 😉

I introduced that yesterday in #2021 (0d620cf). The reason for that is to align the different log level names (ERROR, WARN, INFO, DEBUG, and TRACE), compare with env_logger/src/fmt/mod.rs#L478.
Excerpt with LOG_LEVEL=trace

Stefan also likes the feature and is okay with always displaying the target (compare with dmesg on Linux). So if you have nothing else against this, I will merge this later. :)

I'm still not convinced, it adds unnecessary cluttering imo. Similarly, you only ever call dmesg on Linux if you need to debug something.

Copy link
Contributor

@github-actions github-actions bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Benchmark Results

Benchmark Current: a6ee871 Previous: b9e34fd Performance Ratio
startup_benchmark Build Time 113.33 s 110.50 s 1.03
startup_benchmark File Size 0.91 MB 0.91 MB 1.00
Startup Time - 1 core 0.96 s (±0.03 s) 0.91 s (±0.04 s) 1.06
Startup Time - 2 cores 0.97 s (±0.04 s) 0.92 s (±0.04 s) 1.05
Startup Time - 4 cores 0.98 s (±0.02 s) 0.92 s (±0.04 s) 1.07
multithreaded_benchmark Build Time 112.62 s 110.26 s 1.02
multithreaded_benchmark File Size 0.97 MB 1.02 MB 0.95
Multithreaded Pi Efficiency - 2 Threads 85.10 % (±8.53 %) 88.88 % (±7.88 %) 0.96
Multithreaded Pi Efficiency - 4 Threads 42.34 % (±3.86 %) 44.09 % (±4.43 %) 0.96
Multithreaded Pi Efficiency - 8 Threads 24.74 % (±1.92 %) 25.18 % (±2.08 %) 0.98
micro_benchmarks Build Time 271.73 s 270.98 s 1.00
micro_benchmarks File Size 0.97 MB 1.02 MB 0.95
Scheduling time - 1 thread 150.69 ticks (±21.02 ticks) 153.15 ticks (±22.52 ticks) 0.98
Scheduling time - 2 threads 89.84 ticks (±20.19 ticks) 89.47 ticks (±17.51 ticks) 1.00
Micro - Time for syscall (getpid) 8.08 ticks (±4.50 ticks) 10.74 ticks (±5.67 ticks) 0.75
Memcpy speed - (built_in) block size 4096 62515.09 MByte/s (±44139.97 MByte/s) 59208.17 MByte/s (±42422.24 MByte/s) 1.06
Memcpy speed - (built_in) block size 1048576 15236.82 MByte/s (±12306.67 MByte/s) 15604.80 MByte/s (±12636.68 MByte/s) 0.98
Memcpy speed - (built_in) block size 16777216 10662.93 MByte/s (±8546.99 MByte/s) 11487.12 MByte/s (±9319.97 MByte/s) 0.93
Memset speed - (built_in) block size 4096 62475.27 MByte/s (±44107.06 MByte/s) 59588.60 MByte/s (±42746.95 MByte/s) 1.05
Memset speed - (built_in) block size 1048576 15633.37 MByte/s (±12581.60 MByte/s) 16061.98 MByte/s (±12923.91 MByte/s) 0.97
Memset speed - (built_in) block size 16777216 10931.83 MByte/s (±8716.15 MByte/s) 11848.78 MByte/s (±9579.64 MByte/s) 0.92
Memcpy speed - (rust) block size 4096 55679.43 MByte/s (±40294.27 MByte/s) 57174.91 MByte/s (±41348.10 MByte/s) 0.97
Memcpy speed - (rust) block size 1048576 15613.43 MByte/s (±12596.28 MByte/s) 15863.50 MByte/s (±12841.95 MByte/s) 0.98
Memcpy speed - (rust) block size 16777216 10945.10 MByte/s (±8839.93 MByte/s) 11291.00 MByte/s (±9142.92 MByte/s) 0.97
Memset speed - (rust) block size 4096 56034.35 MByte/s (±40504.61 MByte/s) 57859.11 MByte/s (±41771.72 MByte/s) 0.97
Memset speed - (rust) block size 1048576 16002.92 MByte/s (±12820.29 MByte/s) 16241.25 MByte/s (±13076.73 MByte/s) 0.99
Memset speed - (rust) block size 16777216 11152.99 MByte/s (±8950.58 MByte/s) 11628.25 MByte/s (±9377.45 MByte/s) 0.96
alloc_benchmarks Build Time 269.03 s 267.07 s 1.01
alloc_benchmarks File Size 0.98 MB 0.97 MB 1.00
Allocations - Allocation success 100.00 % 100.00 % 1
Allocations - Deallocation success 100.00 % 100.00 % 1
Allocations - Pre-fail Allocations 100.00 % 100.00 % 1
Allocations - Average Allocation time 17430.83 Ticks (±718.39 Ticks) 17736.97 Ticks (±1105.55 Ticks) 0.98
Allocations - Average Allocation time (no fail) 17430.83 Ticks (±718.39 Ticks) 17736.97 Ticks (±1105.55 Ticks) 0.98
Allocations - Average Deallocation time 2057.50 Ticks (±369.88 Ticks) 2231.85 Ticks (±637.37 Ticks) 0.92
mutex_benchmark Build Time 266.33 s 267.03 s 1.00
mutex_benchmark File Size 0.98 MB 1.02 MB 0.95
Mutex Stress Test Average Time per Iteration - 1 Threads 33.08 ns (±3.02 ns) 33.16 ns (±3.05 ns) 1.00
Mutex Stress Test Average Time per Iteration - 2 Threads 27.36 ns (±3.06 ns) 29.18 ns (±3.00 ns) 0.94

This comment was automatically generated by workflow using github-action-benchmark.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants