Re: [PATCH v2] printk: fix zero-valued printk timestamps in early boot

Hi Tim,

On Sat, 24 Jan 2026 at 20:41, Tim Bird <[email protected]> wrote:
> During early boot, printk timestamps are reported as zero before
> kernel timekeeping starts (e.g. before time_init()).  This
> hinders boot-time optimization efforts.  This period is about 400
> milliseconds for many current desktop and embedded machines
> running Linux.
>
> Add support to save cycles during early boot, and output correct
> timestamp values after timekeeping is initialized.  get_cycles()
> is operational on arm64 and x86_64 from kernel start.  Add code
> and variables to save calibration values used to later convert
> cycle counts to time values in the early printks.  Add a config
> to control the feature.
>
> This yields non-zero timestamps for printks from the very start
> of kernel execution.  The timestamps are relative to the start of
> the architecture-specified counter used in get_cycles
> (e.g. the TSC on x86_64 and cntvct_el0 on arm64).
>
> All timestamps reflect time from power-on instead of time from
> the kernel's timekeeping initialization.
>
> Signed-off-by: Tim Bird <[email protected]>
> ---
> V1 -> V2
>   Remove calibration CONFIG vars
>   Add 'depends on' to restrict arches (to handle ppc bug)
>   Add early_ts_offset to avoid discontinuity
>   Save cycles in ts_nsec, and convert on output
>   Move conditional code to include file (early_times.h)

Thanks for the update!

> --- /dev/null
> +++ b/include/linux/early_times.h
> @@ -0,0 +1,48 @@
> +/* SPDX-License-Identifier: GPL-2.0 */
> +
> +#ifndef _KERNEL_PRINTK_EARLY_TIMES_H
> +#define _KERNEL_PRINTK_EARLY_TIMES_H
> +
> +#include <linux/timex.h>
> +
> +#if defined(CONFIG_EARLY_PRINTK_TIMES)
> +extern u32 early_mult, early_shift;
> +extern u64 early_ts_offset;
> +
> +static inline u64 early_cycles(void)
> +{
> +       return ((u64)get_cycles() | (1ULL << 63));

No need to cast to u64, as the second operand of the OR is u64 anyway.
BIT_ULL(63)

I think it would be good to have a #define for this at the top.

> +}
> +
> +static inline u64 adjust_early_ts(u64 ts)
> +{
> +       /* High bit means ts is a cycle count */
> +       if (unlikely(ts & (1ULL << 63)))
> +               /*
> +                * mask high bit and convert to ns
> +                * Note that early_mult may be 0, but that's OK because
> +                * we'll just multiply by 0 and return 0. This will
> +                * only occur if we're outputting a printk message
> +                * before the calibration of the early timestamp.
> +                * Any output after user space start (eg. from dmesg or
> +                * journalctl) will show correct values.
> +                */
> +               return (((ts & ~(1ULL << 63)) * early_mult) >> early_shift);

Please use the mul_u64_u32_shr() helper.

Please wrap this block in curly braces.
Alternatively, you can invert the logic:

    if (likely(!(ts & DEFINITION_FOR_1ULL_LSH63)))
            return ts + early_ts_offset;

> +
> +       /* If timestamp is already in ns, just add offset */
> +       return ts + early_ts_offset;
> +}
> +#else
> +static inline u64 early_cycles(void)
> +{
> +       return 0;
> +}
> +
> +static inline u64 adjust_early_ts(u64 ts)
> +{
> +       return ts;
> +}
> +#endif /* CONFIG_EARLY_PRINTK_TIMES */
> +
> +#endif /* _KERNEL_PRINTK_EARLY_TIMES_H */
> +
> diff --git a/init/Kconfig b/init/Kconfig
> index fa79feb8fe57..060a22cddd17 100644
> --- a/init/Kconfig
> +++ b/init/Kconfig
> @@ -777,6 +777,18 @@ config IKHEADERS
>           or similar programs.  If you build the headers as a module, a module called
>           kheaders.ko is built which can be loaded on-demand to get access to headers.
>
> +config EARLY_PRINTK_TIMES
> +       bool "Show non-zero printk timestamps early in boot"
> +       default y
> +       depends on PRINTK
> +       depends on ARM64 || X86_64

So for now this is limited to (a few) 64-bit platforms...

> +       help
> +         Use a cycle-counter to provide printk timestamps during
> +         early boot.  This allows seeing timestamps for printks that
> +         would otherwise show as 0.  Note that this will shift the
> +         printk timestamps to be relative to machine power on, instead
> +         of relative to the start of kernel timekeeping.
> +
>  config LOG_BUF_SHIFT
>         int "Kernel log buffer size (16 => 64KB, 17 => 128KB)"
>         range 12 25
> diff --git a/init/main.c b/init/main.c
> index b84818ad9685..cc1af26933f7 100644
> --- a/init/main.c
> +++ b/init/main.c

> @@ -160,6 +163,10 @@ static size_t initargs_offs;
>  # define initargs_offs 0
>  #endif
>
> +#ifdef CONFIG_EARLY_PRINTK_TIMES
> +static u64 start_cycles, start_ns;

cycles_t start_cycles;

(cycles_t is unsigned long, i.e. either 32- or 64-bit).

> +#endif
> +
>  static char *execute_command;
>  static char *ramdisk_execute_command = "/init";
>
> @@ -1118,6 +1125,11 @@ void start_kernel(void)
>         timekeeping_init();
>         time_init();
>
> +#ifdef CONFIG_EARLY_PRINTK_TIMES
> +       start_cycles = get_cycles();
> +       start_ns = local_clock();
> +#endif
> +
>         /* This must be after timekeeping is initialized */
>         random_init();
>
> @@ -1600,6 +1612,20 @@ static int __ref kernel_init(void *unused)
>
>         do_sysctl_args();
>
> +#ifdef CONFIG_EARLY_PRINTK_TIMES
> +       u64 end_cycles, end_ns;

cycles_t end_cycles;

> +
> +       /* set calibration data for early_printk_times */
> +       end_cycles = get_cycles();
> +       end_ns = local_clock();
> +       clocks_calc_mult_shift(&early_mult, &early_shift,
> +               ((end_cycles - start_cycles) * NSEC_PER_SEC)/(end_ns - start_ns),
> +               NSEC_PER_SEC, 50);

mul_u64_u64_div_u64() is probably the best helper that is available
(there is no mul_ulong_u32_div_u64()).

> +       early_ts_offset = ((start_cycles * early_mult) >> early_shift) - start_ns;
> +       pr_debug("Early printk times: mult=%u, shift=%u, offset=%llu ns\n",
> +               early_mult, early_shift, early_ts_offset);
> +#endif
> +
>         if (ramdisk_execute_command) {
>                 ret = run_init_process(ramdisk_execute_command);
>                 if (!ret)

Gr{oetje,eeting}s,

                        Geert

-- 
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds