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

Bird, Tim
2026-01-26T17:12:05Z

> -----Original Message-----
> From: Geert Uytterhoeven <geert@linux-m68k.org>
> 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.

I'll look at this. Is BIT_ULL(63) preferred over (1ULL << 63)?

Do you think something like "HIGH_BIT63" would be good enough?

>
> > +}
> > +
> > +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.
OK. I did not know about that.

I can check, but do you know offhand if timestamps from local_clock() on 32-bit systems are
always 64-bit nanoseconds? I assume so looking at the printk code and
making some assumptions. (But that's dangerous.)

>
> 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;

This is probably a better structure anyway. Will do.

>
> > +
> > + /* 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...

Yes, but it really shouldn't be. I got spooked when 0-day told me that the code
wouldn't link on powerpc, so I restricted it to just machines I was actually testing.
But this should work on some ARM32 and most x8632 platforms. Actually, it should
work on anything that has a cycle-counter from kernel start (some RISC machine
might qualify as well). However, I've seen a few cases where some platforms require
kernel initialization of their cycle-counter, and I wanted to play it safe.

If such platforms are well-behaved and return 0 before they are initialized, it should
still be safe to turn this on - it just won't have any effect.

I plan to do some more investigation of the powerpc error. It was
powerpc-linux-ld: init/main.o: in function `kernel_init':
main.c:(.ref.text+0x144): undefined reference to `__udivdi3'

from the definition of clocks_calc_mult_shift(), which seems to indicate a bug
in the powerpc code. In the long run, I should try to track down that bug rather than
exclude a bunch of other (likely-working) arches. But I was playing it conservative for now.

>
> > + 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).
OK, I’ll use this type.

>
> > +#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;
ack.
>
> > +
> > + /* 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()).

What would the mul_u64_u64_div_u64 do if cycles_t is u32?
Should it sill all work, just not optimized?

>
> > + 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
>
Thanks very much for the review and suggestions. I'm away from my lab for the next week,
but I'd really like to test this on a 32-bit platform that has an early cycle-counter available.
I'll have to do some research. I have some 32-bit platforms in my lab, but I'm not sure which ones
have early-cycle-counter support. Do any of the 32-bit platforms you're familiar with support
early cycle-counters (that is, cycle-counters that are running when the kernel starts, and don't
need any kernel initialization at all)?
-- Tim