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

[Bird, Tim]

Hey Thomas,

Thanks for the review...

> -----Original Message-----
> From: Thomas Gleixner <tglx@xxxxxxxxxx>
> On Tue, Feb 10 2026 at 16:47, Tim Bird 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 processor power-on instead of
> > time from the kernel's timekeeping initialization.
> 
> Can we pretty please _not_ introduce yet another side channel to
> generate time stamps?

Well, this is using get_cycles(), which already exists on most architectures.
This patch just adds a funky way to use cycles (which are available
from power on, rather than from the start of kernel timekeeping) to
allow saving timing data for some early printks (usually about 20 to 60 printks).

Also, my current plan is to back off of adjusting the offset of unrelated (non-pre-time_init()) printks,
and limit the effect in the system to just those first early (pre-time_init()) printks.
The complication to add an offset to all following printks was just to avoid a discontinuity
in printk timestamps, once time_init() was called and "real" timestamps started producing non-zeros.
Given how confusing this seems to have made things, I'm thinking of backing
off of that approach.

> 
> printk()
> 
>    time_ns = local_clock();
that's ts_nsec = local_clock()

> 
> local_clock()
>   local_clock_noinstr()
>   	// After boot
> 	if (static_branch_likely(&__sched_clock_stable))
> 		return sched_clock_noinstr() + __sched_clock_offset;
> 
> 	// Before sched_clock_init()
> 	if (!static_branch_likely(&sched_clock_running))
> 		return sched_clock_noinstr();
> 
> 	clock = sched_clock_local(this_scd());
> 
> On x86:
> sched_clock_noinstr()
>   // bare metal
>   native_sched_clock()
>      // After TSC calibration
>      if (static_branch_likely(&__use_tsc)) {
>        ...
>      }
> 
>   // Jiffies fallback.
> 
> So the obvious solution is to expand the fallback with:
> 
>     if (tsc_available())
>     	return tsc_early_uncalibrated();
> 
>     return jiffies ....;
> 
> As this needs to be supported by the architecture/platform in any case
> there is close to zero benefit from creating complicated generic
> infrastructure for this.

The problem with this is that  tsc_early_uncalibrated() can't return nanoseconds
until after calibration.
I don't think it's a good idea to returns cycles sometimes and nanoseconds
at other times, from a deep-seated timing function like this.
Also tsc_available() might itself depend on initialization that hasn't happened yet
(in early boot).

My approach of saving cycles in ts_nsec  for the early printks works because there's
a limited number of places (only 2) inside the printk code where ts_nsec
is accessed, meaning that the code to detect a cycles value instead of a nanoseconds
value can be constrained to just those two places.  Basically, I'm doing the conversion
from cycles to nanoseconds at printk presentation time, rather than at the time of
printk message submission.

The approach that I originally started with
(see https://lore.kernel.org/linux-embedded/39b09edb-8998-4ebd-a564-7d594434a981@xxxxxxxx/
was to use hardcoded multiplier and shift values for converting from cycles
to nanoseconds.  These multiplier and shift values would be set at kernel
configuration time (ie, using CONFIG values). This approach allows generating nanosecond
values from TSC cycles from the very first kernel instruction, and hence removes the need for a
calibration step at all (but of course, it requires boot-time-optimizing developers to
build a custom kernel for their machine).  This might be a reasonable approach, as the
number of people working on reducing the boot-time of this section of the kernel
(pre-time_init()), is pretty small, IMHO.  Also, the patch for that was much simpler than this
one.

There are other approaches, but none really work early enough in the kernel boot
to not be a pain.   The goal is to provide timing info before: timekeeping init,
jiffies startup, and even CPU features determination, and to keep the effect narrow --
limited only to printks, and the first few pre-time_init() printk messages, at that.

I'm now researching a suggestion from Shashank Balaji to use the existing calibration
data from tsc initialization, which might simplify the current patch even further.  I'll make sure
to CC you on the next version of the patch.

Thanks for your review and feedback of this feature.
 -- Tim