Message-ID:
 <MW5PR13MB5632CEFB9AB7AFDA7334307BFD93A@MW5PR13MB5632.namprd13.prod.outlook.com>
Date: Mon, 26 Jan 2026 17:11:40 +0000
From: "Bird, Tim" <Tim.Bird@...y.com>
To: Geert Uytterhoeven <geert@...ux-m68k.org>
CC: "pmladek@...e.com" <pmladek@...e.com>,
        "rostedt@...dmis.org"
	<rostedt@...dmis.org>,
        "john.ogness@...uxtronix.de"
	<john.ogness@...uxtronix.de>,
        "senozhatsky@...omium.org"
	<senozhatsky@...omium.org>,
        "francesco@...la.it" <francesco@...la.it>,
        "linux-embedded@...r.kernel.org" <linux-embedded@...r.kernel.org>,
        "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>
Subject: RE: [PATCH v2] printk: fix zero-valued printk timestamps in early
 boot



> -----Original Message-----
> From: Geert Uytterhoeven <geert@...ux-m68k.org>
> Hi Tim,
> 
> On Sat, 24 Jan 2026 at 20:41, Tim Bird <tim.bird@...y.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@...y.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

Powered by blists - more mailing lists