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

Geert Uytterhoeven
2026-01-26T10:12:55Z

Hi Tim,

On Sat, 24 Jan 2026 at 20:41, Tim Bird <tim.bird@sony.com> 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 <tim.bird@sony.com>
> ---
> 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 -- geert@linux-m68k.org

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