Re: [PATCH v4 1/1] printk: fix zero-valued printk timestamps in early boot
From: Roberto A. Foglietta
Date: Wed Apr 15 2026 - 05:23:26 EST
On Wed, 15 Apr 2026 at 02:19, Roberto A. Foglietta
<roberto.foglietta@xxxxxxxxx> wrote:
>
> On Wed, 15 Apr 2026 at 00:38, Thomas Gleixner <tglx@xxxxxxxxxx> wrote:
> >
> > On Fri, Apr 10 2026 at 14:37, Tim Bird wrote:
> > > +
> > > +#include <linux/timekeeping.h>
> > > +#ifdef CONFIG_ARM64
> > > +#include <asm/sysreg.h>
> > > +#endif
> > > +
> > > +#ifdef CONFIG_EARLY_CYCLES_KHZ
> > > +static inline u64 early_unsafe_cycles(void)
> > > +{
> > > +#if defined(CONFIG_X86_64)
> > > + /*
> > > + * This rdtsc may happen before secure TSC is initialized, and
> > > + * it is unordered. So please don't use this value for cryptography
> > > + * or after SMP is initialized.
> > > + */
> > > + return rdtsc();
> > > +#elif defined(CONFIG_ARM64)
> > > + return read_sysreg(cntvct_el0);
> > > +#elif defined(CONFIG_RISCV_TIMER)
> > > + u64 val;
> > > +
> > > + asm volatile("rdtime %0" : "=r"(val));
> > > + return val;
> > > +#else
> > > + return 0;
> > > +#endif
> > > +}
> >
> > No. Generic code and generic headers have no business to implement any
> > architecture specific code and there is zero justification for
> > architecture specific #ifdefs in generic code.
>
> This translates in practice in early_unsafe_cycles() various
> instances, one for each architecture supported. Even better a macro
> for each architecture like this example below (untested code, just for
> exemplification):
>
> ts_nsec = local_clock();
> #ifdef CONFIG_EARLY_CYCLES_KHZ
> #if defined(CONFIG_ARM64)
> #include <asm/sysreg.h>
> #define early_unsafe_cycles read_sysreg(cntvct_el0);
> #elif defined(CONFIG_X86_64)
> #define early_unsafe_cycles rdtsc()
> #elif defined(CONFIG_RISCV_TIMER)
> #define early_unsafe_cycles ({ u64 val; asm volatile("rdtime %0" :
> "=r"(val)); val; })
> #else
> #define early_unsafe_cycles 0
> #endif
> + if (unlikely(!ts_nsec))
> + ts_nsec = early_times_ns();
> #endif // CONFIG_EARLY_CYCLES_KHZ
> caller_id = printk_caller_id();
>
> While keeping architectures separate is for abstraction layer best
> practice, in very specific cases abstraction can be a meaningless
> concept or much less important than having a single file for a single
> feature (the complementary way of organising stuff). Because in Linux
> the abstraction layer approach applies for architectures, the gap
> between aesthetic and a specific case like an early boot macros set
> hack for debugging is to clarify the exception from the general rule
> in the header itself.
IMHO, this patch (upstreamed or not) is for a few hackers and it is
not even a tool but a first-outlook or last-resort hack. Therefore the
single point of change that makes sense against spreading stuff that
is supposed to be further hacked isn't the correct approach. The
debate can be about upstreaming this kind of changes, and IMHO this
one still has a sense to be upstreamed among debug features.
I am attaching the path for just sake of independence storage (due my
project github repo linked before is naturally subject to arbitrary
changes by me). It is not supposed to be applied as-is (and probably
cannot be applied anyway) and the patch has been written by hands on a
keyboard. Gemini was used for retrieving information (in a smart man 3
command style) and to collect the ASM code and its fencing.
So the main question is: does this v5 suggested approach bridge the
1-single-point-of-change practical needs with the aim of keeping the
source three? If yes then a V6 is worth being developed to provide the
functionality and propose the upstream (I do not bet in good at the
first write but on resolving the contrast/debate THEN delivery).
Best regards, R-
This is a heavily "refactored by hands" patch (example) based on the one by
From: Tim Bird <tim.bird@xxxxxxxx>
Subject: [PATCH v4 1/1] printk: fix zero-valued printk timestamps in early boot
Date: Fri, 10 Apr 2026 14:37:41 -0600
Message-ID: <20260410203741.997410-2-tim.bird@xxxxxxxx>
During early boot, printk timestamps are reported as zero before
kernel timekeeping starts (i.e. before time_init()). This
hinders boot-time optimization efforts. This period ranges from
17 to 1700 milliseconds on different embedded machines running Linux.
Add support for early timestamps based on processor cycle-generators
that need no kernel initialization.This feature isn't intended for a
generic distro kernels but for temporary use during kernel development
and boot-time research and optimization by kernel hackers only.
This yields non-zero timestamps for printks from the very start
of kernel execution. The timestamps are relative to the start of
an architecture-specific counter (e.g. tsc on x86_64 and cntvct_el0
on arm64). Affected timestamps reflect cycle counter related values
since init (usually machine power-on or virtual machine start) instead
of time from the kernel's timekeeping initialization. This results in
a discontinuity in the printk timestamp values, one time, when
kernel timekeeping starts.
Signed-off-by: Tim Bird <tim.bird@xxxxxxxx>
Signed-off-by: Roberto A. Foglietta <roberto.foglietta@xxxxxxxxx>
---
V5 -> V4
Rationale: single point of change hack for printk.
It provides a feature for kernel hackers willing to profiling the early boot
with a basic printk approach (rather than using HW monitors which might not
be available or immediately available). Thus, it is a first-look or a last
resort hack profiling feature. Something that isn't good to spread around
the kernel sources tree and it is fine to have into a single header file.
V3 -> V4
Replace config vars with single one: CONFIG_EARLY_CYCLES_KHZ
Replace runtime calibration with static config variable
Remove reference to get_cycles()
Add support for RISCV platforms
V2 -> V3
Default CONFIG option to 'n'
Move more code into early_times.h (reduce ifdefs in init/main.c)
Use match64 helper routines
Use cycles_t instead of u64 type
Add #defines for EARLY_CYCLES_BIT and EARLY_CYCLES_MASK
Invert if logic in adjust_early_ts()
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>
diff -pruN /dev/null kernel/printk/early_times.h
new file mode 100644
index 000000000000..82bacfd0e26b
--- /dev/null
+++ kernel/printk/early_times.h
@@ -0,0 +1,26 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+
+#ifndef _EARLY_TIMES_H
+#define _EARLY_TIMES_H
+
+#include <linux/timekeeping.h>
+
+/*
+ * Fencing isn't optional here, otherwise unreliable values displaying
+ */
+#if defined(CONFIG_ARM64)
+ #include <asm/sysreg.h>
+ #define __early_raw_cycles ({ u64 val; \
+ asm volatile("isb; mrs %0, cntvct_el0" : "=r"(val)); val; })
+#elif defined(CONFIG_X86_64)
+ #define __early_raw_cycles ({ u64 val; \
+ asm volatile("lfence; rdtsc; shl $32, %%rdx; or %%rdx, %%rax" \
+ : "=a"(val) : : "rdx"); val; })
+#elif defined(CONFIG_RISCV_TIMER)
+ #define __early_raw_cycles ({ u64 val; \
+ asm volatile("fence; rdtime %0" : "=r"(val)); val; })
+#else
+ #define __early_raw_cycles 0
+#endif
+
+#endif /* _EARLY_TIMES_H */
diff --git a/init/Kconfig b/init/Kconfig
index 7484cd703bc1..40c3123c2c27 100644
--- a/init/Kconfig
+++ b/init/Kconfig
@@ -792,6 +792,26 @@ 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_BOOT_TIMINGS
+ int "Early boot printk shows times in raw cycle counter style"
+ default 0
+ depends on PRINTK
+ depends on ARM64 || X86_64 || RISCV_TIMER
+ help
+ Boolean value, disabled by default.
+
+ Set this to provide cycles information for printks in early boot
+ (before the start of kernel timekeeping), that would otherwise
+ show as 0. Profiling by relative monotonic values, not time.
+
+ Note that this causes the kernel to show, for some early printks,
+ cycles that are relative to processor power on, instead of
+ relative to the start of kernel timekeeping. When kernel
+ timekeeping starts, the timestamps values reset, causing
+ a discontinuity in the timestamp values.
+
+ If unsure, keep it disabled as per its default.
+
config LOG_BUF_SHIFT
int "Kernel log buffer size (16 => 64KB, 17 => 128KB)"
range 12 25
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 0323149548f6..ddeab81f04ef 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2294,6 +2295,8 @@ int vprintk_store(int facility, int level,
* timestamp with respect to the caller.
*/
ts_nsec = local_clock();
+#if CONFIG_EARLY_BOOT_TIMINGS
+#include "early_times.h"
+ /*
+ * Very few developers are using this feature and they're expecting to deal
+ * with it as a single point of change hack to be further customised by them.
+ * The right shift by 2^10 is a raw extimation to provide 6-figure within the
+ * first second when the kernel internal cycle/nS calibration isn't ready yet.
+ */
+ if (unlikely(!ts_nsec))
+ ts_nsec = __early_raw_cycles >> 10;
+#endif
+
caller_id = printk_caller_id();
--
2.43.0